Android ANR的trace文件基本信息解读

ANR堆栈文件的抓取

• android6以下可以直接读取/data/anr目录下的trace.txt文件，然后过滤出自己进程的anr文件即可
• android6及以上，没有读取/data/anr的权限，需要native层通过拦截SIGQUIT信号，结合消息机制msg的when超时时间，底层dump堆栈信息。详细原理详见微信技术团队的分享：微信Android客户端的ANR监控方案

Android ANR的trace文件基本信息解读

• 示例

"main" prio=5 tid=1 Native
  | group="main" sCount=0 dsCount=0 flags=0 obj=0x727c02f8 self=0xb400007a2f210800
  | sysTid=339 nice=-10 cgrp=default sched=0/0 handle=0x7ab698d500
  | state=? schedstat=( 0 0 0 ) utm=0 stm=0 core=0 HZ=100
  | stack=0x7fc8197000-0x7fc8199000 stackSize=8192KB
  | held mutexes=
  at android.os.MessageQueue.nativePollOnce(Native method)
  at android.os.MessageQueue.next(MessageQueue.java:339)
  at android.os.Looper.loop(Looper.java:200)
  at android.app.ActivityThread.main(ActivityThread.java:8312)
  at java.lang.reflect.Method.invoke(Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:632)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1049)

线程基本信息

• 线程优先级：prio=5 (主线程均是5)
• 线程ID： tid=1 主线程的id一般都是1
• 线程状态：Native ：表示正在调用JNI
  • 还有其他多种状态，表示发生ANR时主线程的状态
• 线程组名称：group=“main”
• 线程被挂起的次数：sCount=0
  • 在等待GC时，有时候挂起的线程数量比较多
• 线程被调试器挂起的次数：dsCount=0
• 线程的java的对象地址：obj= 0x7682ab30
• 线程本身的Native对象地址：self=0x7bd3815c00线程调度信息：

线程优先级信息

• Linux系统中内核线程ID: sysTid=6317与主线程的进程号相同
• 线程调度优先级：nice=-10
• 线程调度组：cgrp=default
• 线程调度策略和优先级：sched=0/0
• 线程处理函数地址：handle= 0x7c59fc8548

线程状态信息

• 线程调度状态：state=S
• 线程在CPU中的执行时间、线程等待时间、线程执行的时间片长度：schedstat=(1009468742 32888019 224)
• 线程在用户态中的调度时间值：utm=91
• 线程在内核态中的调度时间值：stm=9
• 最后执行这个线程的CPU核序号：core=4

线程堆栈信息

• 堆栈地址和大小：stack=0x7ff27e1000-0x7ff27e3000 stackSize=8MB

ANR中的主线程状态及ANR示例分析

Blocked

• case 1

"main" prio=5 tid=1 Blocked
  | group="main" sCount=0 dsCount=0 flags=0 obj=0x72996758 self=0xb400007ac7e10800
  | sysTid=28366 nice=-10 cgrp=default sched=0/0 handle=0x7b4f71b500
  | state=? schedstat=( 0 0 0 ) utm=0 stm=0 core=0 HZ=100
  | stack=0x7fe0a67000-0x7fe0a69000 stackSize=8192KB
  | held mutexes=
  at com.autonavi.base.ae.gmap.GLMapEngine.addGestureMessage(SourceFile:-1)
  - waiting to lock <0x0f62c521> (a com.autonavi.base.ae.gmap.GLMapEngine) held by thread 96
  at com.amap.api.mapcore.util.c.addGestureMapMessage(SourceFile:2892)
  at com.amap.api.mapcore.util.p$c.b(SourceFile:801)
  at com.amap.api.mapcore.util.am.a(SourceFile:104)
  at com.amap.api.mapcore.util.ak.d(SourceFile:61)
  at com.amap.api.mapcore.util.p.a(SourceFile:195)
  at com.amap.api.mapcore.util.c.onTouchEvent(SourceFile:1795)
  at com.amap.api.mapcore.util.e.onTouchEvent(SourceFile:47)

• 分析：
  • GLMapEngine锁被线程96持有，主线程一直等待到ANR，需要解决锁等待的问题
• case 2

"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 cgrp=apps/bg_non_interactive handle=0xb6f4fb4c
  | sysTid=4232 nice=0 sched=0/0 cgrp=apps/bg_non_interactive handle=0xb6f4fb4c
  | state=S schedstat=( 93912199183 67364592009 177636 ) utm=7567 stm=1824 core=1 HZ=100
  | heldMutexes=
 at android.hardware.display.DisplayManagerGlobal.getDisplayInfo(DisplayManagerGlobal.java:172)
 at android.hardware.display.DisplayManagerGlobal.getDisplayInfo(DisplayManagerGlobal.java:166)
 at android.hardware.display.DisplayManagerGlobal.getDisplayInfo(DisplayManagerGlobal.java:159)

• 分析
  • cgrp=apps/bg_non_interactive 表示app在后台；
  • sCount=1有一个线程被挂起；
  • nice=0 压后台时，线程优先级降低，nice值越小（负数），优先级越高
  • schedstat( 93912199183 67364592009 177636 )，表示线程执行时间很长

Native

• case 1

"main" prio=5 tid=1 Native
  | group="main" sCount=0 dsCount=0 flags=0 obj=0x727c02f8 self=0xb400007a2f210800
  | sysTid=339 nice=-10 cgrp=default sched=0/0 handle=0x7ab698d500
  | state=? schedstat=( 0 0 0 ) utm=0 stm=0 core=0</