Android Native Crash的log分析和定位

非原创,学习于:

https://blog.csdn.net/helldevil/article/details/6682211

 

作为测试,如果能掌握log定位是一件很好的事情。

在日常工作中,有机会也会进行学习

但学习的相对于开发来说,会较为浅层。以下相关信息有做一定隐藏。

-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

09-22 09:39:43.083 F/libc ( 9479): Fatal signal 11 (SIGSEGV), code 2 (SEGV_ACCERR), fault addr 0x7a05b46000 in tid 9714 (Thread-5), pid 9479 (m.xxxx.gallery)
09-22 09:39:43.247 F/DEBUG ( 9733): *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
09-22 09:39:43.248 F/DEBUG ( 9733): Build fingerprint: ‘xxxx/6025H/HONG_KONG:11/RP1A.200709.001/7KXX:user/release-keys‘
09-22 09:39:43.248 F/DEBUG ( 9733): Revision: ‘0‘
09-22 09:39:43.248 F/DEBUG ( 9733): ABI: ‘arm64‘
09-22 09:39:43.249 F/DEBUG ( 9733): Timestamp: 2020-09-22 09:39:43+0800
09-22 09:39:43.249 F/DEBUG ( 9733): pid: 9479, tid: 9714, name: Thread-5 >>> com.xxxx.gallery <<<
09-22 09:39:43.249 F/DEBUG ( 9733): uid: 10099
09-22 09:39:43.249 F/DEBUG ( 9733): signal 11 (SIGSEGV), code 2 (SEGV_ACCERR), fault addr 0x7a05b46000
09-22 09:39:43.249 F/DEBUG ( 9733): x0 0000007763d89c70 x1 0000000000000002 x2 0000007a0428b56c x3 0000007a0428db9c
09-22 09:39:43.249 F/DEBUG ( 9733): x4 0000000000000001 x5 0000000000000008 x6 0000007a0428b4e8 x7 0000000000000025
09-22 09:39:43.249 F/DEBUG ( 9733): x8 0000000000000023 x9 000000000000000a x10 0000000000000021 x11 000000000000004a
09-22 09:39:43.249 F/DEBUG ( 9733): x12 0000007a04289050 x13 0000007a05b45fe4 x14 0000007a0428db18 x15 0000000000000021
09-22 09:39:43.250 F/DEBUG ( 9733): x16 0000000000000048 x17 0000000000000001 x18 0000007a0428b680 x19 0000000000000001
09-22 09:39:43.250 F/DEBUG ( 9733): x20 0000007a0428b5e0 x21 0000007a0428dc10 x22 0000000000000009 x23 0000000000000084
09-22 09:39:43.250 F/DEBUG ( 9733): x24 000000770376bcb8 x25 000000770376bb50 x26 0000007a0428b664 x27 0000007a0428dc94
09-22 09:39:43.250 F/DEBUG ( 9733): x28 0000007a05b45f58 x29 0000007a05b45ecc
09-22 09:39:43.250 F/DEBUG ( 9733): lr 0000007a05b45e50 sp 0000007763d89650 pc 0000007762910674 pst 0000000020000000
09-22 09:39:43.500 F/DEBUG ( 9733): backtrace:
09-22 09:39:43.500 F/DEBUG ( 9733): #00 pc 00000000002eb674 /data/app/~~JBZ8-fwaJ0pWsj4hEf8wkQ==/com.xxxx.gallery-BwSA1NtaDN7WDKjYMNNIOw==/base.apk!libfacenet.so (offset 0x3552000) (BuildId: cd8fc953d21f932a219d2676a37ec6747333fb1f)
09-22 09:39:43.500 F/DEBUG ( 9733): #01 pc 00000000002e2e90 /data/app/~~JBZ8-fwaJ0pWsj4hEf8wkQ==/com.xxxx.gallery-BwSA1NtaDN7WDKjYMNNIOw==/base.apk!libfacenet.so (offset 0x3552000) (BuildId: cd8fc953d21f932a219d2676a37ec6747333fb1f)
09-22 09:39:43.500 F/DEBUG ( 9733): #02 pc 00000000002dbac4 /data/app/~~JBZ8-fwaJ0pWsj4hEf8wkQ==/com.xxxx.gallery-BwSA1NtaDN7WDKjYMNNIOw==/base.apk!libfacenet.so (offset 0x3552000) (BuildId: 

...
09-22 09:39:43.508 F/DEBUG ( 9733): #40 pc 000000000055c384 /apex/com.android.art/lib64/libart.so (art::JValue art::InvokeVirtualOrInterfaceWithJValues<art::ArtMethod*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, art::ArtMethod*, jvalue const*)+460) (BuildId: 132c9fd75471ac7a6d1d7331ebfeeb49)
09-22 09:39:43.508 F/DEBUG ( 9733): #41 pc 00000000005ac204 /apex/com.android.art/lib64/libart.so (art::Thread::CreateCallback(void*)+1308) (BuildId: 132c9fd75471ac7a6d1d7331ebfeeb49)
09-22 09:39:43.508 F/DEBUG ( 9733): #42 pc 00000000000b0658 /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+64) (BuildId: b32164423ca0fcdb55f8214db90688c3)
09-22 09:39:43.508 F/DEBUG ( 9733): #43 pc 0000000000050150 /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64) (BuildId: b32164423ca0fcdb55f8214db90688c3)
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

1.怎么判断是Native crash?

有时候是不会有提示框出现,行为可以表现为闪退。

查看log,有以下信息:

Fatal signal 11 (SIGSEGV)

可过滤DEBUG 级的log

上一张别人的图,简单分析log信息:

Android Native Crash的log分析和定位

 

 

 

2.怎么进一步分析?

2.1 看橙色语句:

09-22 09:39:43.249 F/DEBUG ( 9733): pid: 9479, tid: 9714, name: Thread-5 >>> com.xxxx.gallery <<<

橙色部分是让我们确认问题到底发生在哪个线程中,是主线程还是子线程;

这个的判断依据是:

如果PID和TID相同,问题则在主线程

如果PID和TID不相同,那么问题则出在子线程

从上面例子看,该crash发生在子线程。

 

2.2 看backtrace下的log

就是下面这一堆。

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

09-22 09:39:43.500 F/DEBUG ( 9733): backtrace:
09-22 09:39:43.500 F/DEBUG ( 9733): #00 pc 00000000002eb674 /data/app/~~JBZ8-fwaJ0pWsj4hEf8wkQ==/com.xxxx.gallery-BwSA1NtaDN7WDKjYMNNIOw==/base.apk!libfacenet.so (offset 0x3552000) (BuildId: cd8fc953d21f932a219d2676a37ec6747333fb1f)
09-22 09:39:43.500 F/DEBUG ( 9733): #01 pc 00000000002e2e90 /data/app/~~JBZ8-fwaJ0pWsj4hEf8wkQ==/com.xxxx.gallery-BwSA1NtaDN7WDKjYMNNIOw==/base.apk!libfacenet.so (offset 0x3552000) (BuildId: cd8fc953d21f932a219d2676a37ec6747333fb1f)
09-22 09:39:43.500 F/DEBUG ( 9733): #02 pc 00000000002dbac4 /data/app/~~JBZ8-fwaJ0pWsj4hEf8wkQ==/com.xxxx.gallery-BwSA1NtaDN7WDKjYMNNIOw==/base.apk!libfacenet.so (offset 0x3552000) (BuildId: 

...
09-22 09:39:43.508 F/DEBUG ( 9733): #40 pc 000000000055c384 /apex/com.android.art/lib64/libart.so (art::JValue art::InvokeVirtualOrInterfaceWithJValues<art::ArtMethod*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, art::ArtMethod*, jvalue const*)+460) (BuildId: 132c9fd75471ac7a6d1d7331ebfeeb49)
09-22 09:39:43.508 F/DEBUG ( 9733): #41 pc 00000000005ac204 /apex/com.android.art/lib64/libart.so (art::Thread::CreateCallback(void*)+1308) (BuildId: 132c9fd75471ac7a6d1d7331ebfeeb49)
09-22 09:39:43.508 F/DEBUG ( 9733): #42 pc 00000000000b0658 /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+64) (BuildId: b32164423ca0fcdb55f8214db90688c3)
09-22 09:39:43.508 F/DEBUG ( 9733): #43 pc 0000000000050150 /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64) (BuildId: b32164423ca0fcdb55f8214db90688c3)

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

这里所显示的程序的执行流程,实际的执行顺序是#XX-->#00

所以一开始我们的目的是分析第一个出现问题的动态连接库

 #43 pc 0000000000050150 /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64) (BuildId: b32164423ca0fcdb55f8214db90688c3)

再一级一级往上分析,通常都是分析到自己代码库里面部分。

 

3.定位问题

这一部分涉及到代码分析,因为缺少相关环境,所以这部分会以学习博客内容为主。有兴趣也可以去看原博客。

 

所以一开始我们的目的是分析第一个出现问题的动态连接库
   #15  pc 0001173c  /system/lib/libc.so

 A. 首先按图索骥,找到你的目标,libc.so这个一般会在你编译完的目标目录下,也就是out/target/product/your_pro/system/lib这个目录下。

B. 一般你如果用的是还像样的linux系统,会有个地址解析的命令:

      addr2line(负责解析动态连接库的)

        (如果你是悲剧,没有这个命令,那好吧, google早就预料到会有象你这样的悲剧人,他们在prebuilt/linux-x86/toolchain/arm-eabi-4.4.0/bin/arm-eabi-addr2line,给您准备了个,咋就用这个吧,功能一样,没啥区别)

     addr2line -e -f libc.so 0001173c  //红色是你的目标库,蓝色是你出问题的地址,看看#15这行

    结果出现:

  pthread_create

        0

 

这个只是告诉你函数入口,至于具体执行到这个函数的哪个地方挂了,还得再看。

C. 找到了是哪个部分出了问题,继续分析

   使用

    objdump -S -D libc.so > deassmble_libc.txt

        反汇编下你的动态连接库文件,并且将它写入一个文件中。

   打开这个反汇编过后的重定向文件,在查询的时候输入1173c这个偏移地址,你会看到:

  00011684 <pthread_create>:
   11684:       e92d4ff0        push    {r4, r5, r6, r7, r8, r9, sl, fp, lr}
   11688:       e24dd01c        sub     sp, sp, #28     ; 0x1c
   1168c:       e1a06001        mov     r6, r1
   11690:       e1a08002        mov     r8, r2
   11694:       e1a09003        mov     r9, r3
   11698:       e3a04001        mov     r4, #1  ; 0x1
   1169c:       e59f521c        ldr     r5, [pc, #540]  ; 118c0 <pthread_create+0x23c>
   ...

   1173c:       ebffec2b        bl      c7f0 <__pthread_clone>-->就是他了,对你成功了。

   ...

这个是ARM汇编,需要你翻译成对应的C函数去看,这里我就不做解释了,照着前面的步骤.(PS:估计就是步骤B?)

 

对上面中#15-->#00 一共16行慢慢去找,直到找到#00行的问题函数,其实,最后一个#00行的是最重要的(前面不找也行,但是可以多给你提供问题信息,和流程),因为他是第一目击者,也是Crash前的第一现场。所以找到这个函数很重要.

 

 

假设我们最后经过万里长针发现#00的出错的地方是pXX->member挂了

那么你可以怀疑两个地方:

1 您的指针是空指针,但是现实与理想总是十万八千里,多数情况下很少出现,而且你分析代码后,也会对自己说怎么可能。绝大多数情况下,从我的经验来讲,很少会有空指针这种低级错误,但是不排除哪个2货出现了这么个问题。如果是这个问题,那么恭喜你,你很幸运。

2 还有就是怀疑越界和内存地址被挤占。就拿我以前的经验,指针不是空,但是根据汇编码看,是访问成员变量挂了,这个地址肯定是被占用了。

  

  针对第2种比较恶心的情况,就需要你看整个log的流程了,需要你看下主要的mainlog关于出现crash前的动作,看看是哪个孙子占用的,以最近原则为先,从下往上看,唉,说句实在话,李白的一句话可以形容整个过程:"蜀道难,难于上青天啊"。工作量大,而且要细致。我也没什么办法。。。

 

  还有一种情况,就是内存不够,导致了您的地址被挤占了,出现low memory, no more ...这样的语句,以及大量出现GC_FOR_MALLOC关于GC的东西(如果是少量的,可以忽略,大量的话),呵呵表明你的某个进程在吞噬你的内存,存在内存泄漏。坑爹啊,这个问题,是最难查的,需要你花大量时间,去看内存的变化。一般看内存的情况是

cat /proc/meminfo 

 

  空闲内存=buffer+cache+free这三个字段,Active字段是已经使用的内存,Total不用说,是总的物理内存。(记住 free不高,并不代表你的内存空闲不高,海水不可斗量,需要看全了3个字段的总和才是空闲内存)

  如果你想具体跟踪每个进程的内存使用情况,还是在/proc下面,对应了N多的数字文件,那个其实是PID号,进去后cat status可以看到

  VMRSS XXXKB就是你当前进程的使用内存量,此外还有一些其他的内存数据,包括页等等

  里面还有很多有用的数据,如果你想跟踪所有的进程的内存情况,推介大家可以看看linux ps命令的源码,看看人家是怎么在/proc下遍历进程,并且提取属性值的。

 

写个daemon,跟踪一段时间,记录下各进程内存的变化,然后就是通宵的分析。。。。

总之,这类问题,很难定位,也很难解决,需要花时间,精力去分析。

Android Native Crash的log分析和定位

上一篇:Android程序员现状:没有架构师的命,却得了架构师的病!


下一篇:基于时间延迟的Python验证脚本