Android Native Crash问题排查思路

背景:定位难

对于Android APP而言,native层Crash相比于Java层更难捕获与定位,因为so的代码通常不可见,而且,一些第三方so的crash或者系统的更难定位,堆栈信息非常少:参考下面的几个native crash实例

image.png

甚至即时全量打印Log信息,也只能得到一些不太方便定位的日志,无法直接定位问题

09-14 10:14:36.590  1361  1361 I /system/bin/tombstoned: received crash request for pid 5908
09-14 10:14:36.591  5944  5944 I crash_dump64: performing dump of process 5687 (target tid = 5908)
09-14 10:14:36.607  5944  5944 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
09-14 10:14:36.608  5944  5944 F DEBUG   : Build fingerprint: 'Xiaomi/vangogh/vangogh:10/QKQ1.191222.002/V12.0.6.0.QJVCNXM:user/release-keys'
09-14 10:14:36.608  5944  5944 F DEBUG   : Revision: '0'
09-14 10:14:36.608  5944  5944 F DEBUG   : ABI: 'arm64'
09-14 10:14:36.608  5944  5944 F DEBUG   : Timestamp: 2021-09-14 10:14:36+0800
09-14 10:14:36.608  5944  5944 F DEBUG   : pid: 5687, tid: 5908, name: nioEventLoopGro  >>> com.netxx.xaxxxn <<<
09-14 10:14:36.608  5944  5944 F DEBUG   : uid: 10312
09-14 10:14:36.608  5944  5944 F DEBUG   : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x4
09-14 10:14:36.608  5944  5944 F DEBUG   : Cause: null pointer dereference
09-14 10:14:36.608  5944  5944 F DEBUG   :     x0  0000000000000000  x1  0000000014d85fb0  x2  0000000015100bf8  x3  0000000000000000
09-14 10:14:36.608  5944  5944 F DEBUG   :     x4  0000000015100c18  x5  000000000000005a  x6  0000000015100c30  x7  0000000000000018
09-14 10:14:36.608  5944  5944 F DEBUG   :     x8  0000000000000000  x9  20454cc47a8eade3  x10 00000000005c0000  x11 000000000000004b
09-14 10:14:36.608  5944  5944 F DEBUG   :     x12 000000000000001f  x13 0000000000000000  x14 00000000a2018668  x15 0000000000000010
09-14 10:14:36.608  5944  5944 F DEBUG   :     x16 0000000000000000  x17 0000000000054402  x18 00000077328bc000  x19 00000077616e0c00
09-14 10:14:36.608  5944  5944 F DEBUG   :     x20 0000000000000001  x21 00000000151004a0  x22 0000000014d85fb0  x23 00000000a1f03180
09-14 10:14:36.608  5944  5944 F DEBUG   :     x24 0000000000000001  x25 0000000000000000  x26 0000000000000003  x27 00000000151000b8
09-14 10:14:36.608  5944  5944 F DEBUG   :     x28 0000000000000000  x29 00000000151009b0
09-14 10:14:36.608  5944  5944 F DEBUG   :     sp  000000773536e4f0  lr  000000779431b80c  pc  0000007794240260

如上,虽然能看到 Cause: null pointer dereference,但是到底是什么代码导致的,没有非常明确的消息,不像Java层Crash有非常清晰堆栈,这就让Native的crash定位非常头痛。

如何定位native crash

对于Crash而言,精确的定位等于成功的一半。如何通过工具定位到native crash呢,如果是自己实现的so库,一般而言还是会有相应的日志打印出来的,本文主要针对一些特殊的so,尤其是不存在源码的so,对于这种场景如何定位,最重要当然还是复现:匹配对应的机型、环境、不断重试复现线上问题,一旦发生Crash后就些蛛丝马迹可查,本文以线上偶发的一个ARM64升级为例子,分析下定位流程:通过归纳,重试,复现场景后,便可以去查找问题日志,这个时候有一个挺好用的方法:bugreport命令:

$ adb bugreport  ~\  

app crash 的时候,系统会保存一个tombstone文件到/data/tombstones目录,该命令会导出最近的crash相关信息,我们可以通过bugreport导出,导出后它是一个zip包的形式,解压后如下

image.png

对于每个tombstone,如果是native crash,打开后大概会看到如下日志:

image.png

最上面的这些日志是最重要的,它包含了发生crash的线程是哪个,发的日志调用帧是哪个,到这里基本能很大程度上帮助我们实现问题的定位了,也就是基于bugreport + tombstone。

问题分析

线上ARM64升级的Crash只发生在Android10的系统上,具体到我们这个BUG,最终归宿到

arm64/base.odex (BakerReadBarrierThunkAcquire_r15_r0_2)   

Cause: null pointer dereference

但是上述的问题看起来跟如下帧似乎没有任何关系

arm64/base.odex (com.netease.mail.profiler.handler.BaseHandler.stopTrace+360)

Java层的代码,怎么忽然就跑到arm64/base.odex (BakerReadBarrierThunk中去了呢?不防分析一下完整的调用帧:

backtrace:
      #00 pc 00000000008ee260  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (BakerReadBarrierThunkAcquire_r15_r0_2)
      #01 pc 00000000009c9808  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (com.netease.mail.profiler.handler.BaseHandler.stopTrace+360)
      #02 pc 00000000009b3cc4  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (com.netease.mail.profiler.handler.TailHandler$1.operationComplete+212)
      #03 pc 00000000009b3b8c  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (com.netease.mail.android.wzp.util.Util$1.operationComplete [DEDUPED]+108)
      #04 pc 0000000000b93180  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.util.concurrent.DefaultPromise.notifyListener0+80)
      #05 pc 0000000000b9370c  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.util.concurrent.DefaultPromise.notifyListeners+988)
      #06 pc 0000000000b94e3c  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.util.concurrent.DefaultPromise.trySuccess+92)
      #07 pc 0000000000ba499c  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.channel.DefaultChannelPromise.trySuccess+44)
      #08 pc 0000000000b90ef4  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.fulfillConnectPromise+84)
      #09 pc 0000000000b91850  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect+192)
      #10 pc 0000000000bb390c  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.channel.nio.NioEventLoop.processSelectedKey+444)
      #11 pc 0000000000bb3bf8  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized+312)
      #12 pc 0000000000bb55b8  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.channel.nio.NioEventLoop.run+824)
      #13 pc 0000000000ae1580  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.util.concurrent.SingleThreadEventExecutor$2.run+128)
      #14 pc 0000000000adf068  /data/app/com.netease.yanxuan-YLeR3gwwgd3DyIUBNJZ8cA==/oat/arm64/base.odex (io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run+72)
      #15 pc 00000000004afbb8  /system/framework/arm64/boot.oat (java.lang.Thread.run+72) (BuildId: 65cd48ea51183eb3b4cdfeb64ca2b90a9de89ffe)
      #16 pc 0000000000137334  /apex/com.android.runtime/lib64/libart.so (art_quick_invoke_stub+548) (BuildId: fc24b8afa1bd5f1872cc1a38bcfa1cdc)
      #17 pc 0000000000145fec  /apex/com.android.runtime/lib64/libart.so (art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)+244) (BuildId: fc24b8afa1bd5f1872cc1a38bcfa1cdc)
      #18 pc 00000000004b0d98  /apex/com.android.runtime/lib64/libart.so (art::(anonymous namespace)::InvokeWithArgArray(art::ScopedObjectAccessAlreadyRunnable const&, art::ArtMethod*, art::(anonymous namespace)::ArgArray*, art::JValue*, char const*)+104) (BuildId: fc24b8afa1bd5f1872cc1a38bcfa1cdc)
      #19 pc 00000000004b1eac  /apex/com.android.runtime/lib64/libart.so (art::InvokeVirtualOrInterfaceWithJValues(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jmethodID*, jvalue const*)+416) (BuildId: fc24b8afa1bd5f1872cc1a38bcfa1cdc)
      #20 pc 00000000004f2868  /apex/com.android.runtime/lib64/libart.so (art::Thread::CreateCallback(void*)+1176) (BuildId: fc24b8afa1bd5f1872cc1a38bcfa1cdc)
      #21 pc 00000000000e69e0  /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+36) (BuildId: 1eb18e444251dc07dff5ebd93fce105c)
      #22 pc 0000000000084b6c  /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64) (BuildId: 1eb18e444251dc07dff5ebd93fce105c)

从#22帧开始看出这个是一个ART解释执行的过程,Android中基本所有线程栈都是这种形式,那么最终就可以认为是解释BaseHandler.stopTrace这句的时候,出现了null pointer dereference这样一个异常,为甚会这样呢?由于在系统上有共性:只有Android10系统的ARM64设备上出现,所以有理由怀疑Android10的源码在BakerReadBarrierThunkAcquire_r15_r0_2这里的处理上有什么不对劲,通过检索akerReadBarrierThunkAcquire_r15_r0_2字符串,发现code_generator_arm64.cc源码CompileBakerReadBarrierThunk函数最终输出了这段日志:

image.png

对比Android10与Android 11源码发现有一处很明确的不同,在Field Load使用之前,多加了一个空检查的Case:

image.png

解释执行代码实在是看不懂:摘录了下这条记录的log Fix null checks on volatile reference field loads on ARM64.如下:

Fix null checks on volatile reference field loads on ARM64.

ART's compiler adds a null check HIR instruction before each field
load HIR instruction created in the instruction builder phase. When
implicit null checks are allowed, the compiler elides the null check
if it can be turned into an implicit one (i.e. if the offset is within
a system page range).

On ARM64, the Baker read barrier thunk built for field reference loads
needs to check the lock word of the holder of the field, and thus
includes an explicit null check if no null check has been done before.
However, this was not done for volatile loads (implemented with a
load-acquire instruction on ARM64). This change adds this missing null
check.

意思就是:对于volatile修饰的变量(映射为load-acquire instruction),加上空检查,避免运行时空指针。Android 10没有做这个空检查,该commit就是为修复该BUG,回到业务中发现,确实有地方用了多线程及volatile,并且有一定概率出现空指针,处理掉这段逻辑即可。

总结

最主要的是结合bugreport及tombstone文件做好定位,定位问题后,才方便解决。

参考文档

https://wufengxue.github.io/2020/06/22/wechat-voice-codec-SEGV_MAPERR.html 有效参考分析工具

https://developer.android.com/ndk/guides/ndk-stack

作者:看书的小蜗牛
原文链接: Android Native Crash问题排查思路

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 206,126评论 6 481
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 88,254评论 2 382
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 152,445评论 0 341
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 55,185评论 1 278
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 64,178评论 5 371
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,970评论 1 284
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,276评论 3 399
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,927评论 0 259
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 43,400评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,883评论 2 323
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,997评论 1 333
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,646评论 4 322
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,213评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,204评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,423评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,423评论 2 352
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,722评论 2 345