ANR分析流程

0

前言:

ANR触发条件?

分析Anr需要哪些信息?

Anr trace file关键信息采集

Anr分析流程

file

1 ANR类型

出现ANR的一般有以下几种类型:

1.1 KeyDispatchTimeout(常见)

input事件在5S内没有处理完成发生了ANR。
logcat日志关键字:Inputevent dispatching timed out(nofocus window/responding timeout)

1.2 BroadcastTimeout

前台Broadcast:onReceiver在10S内没有处理完成发生ANR。
后台Broadcast:onReceiver在60s内没有处理完成发生ANR。
logcat日志关键字:Timeoutof broadcast BroadcastRecord

1.3 ServiceTimeout

前台Service:onCreate,onStart,onBind等生命周期在10s内没有处理完成发生ANR。
后台Service:onCreate,onStart,onBind等生命周期在100s内没有处理完成发生ANR
logcat日志关键字:Timeoutexecuting service

1.4 ContentProviderTimeout

ContentProvider 在10S内没有处理完成发生ANR。 logcat日志关键字:timeoutpublishing content providers

02 分析Anr需要哪些信息

•data/anr/trace

•Bbklog

•涉及到binder阻塞需要/d/binder

•涉及到fd leak需要/proc/anrpid/fdinfo

•涉及整机资源苛刻导致,抓Atrace分析。

03 Anr trace file信息详解

•发生anr的时间戳

•发生anr的进程号

•发生anr的进程包名

•发生anr的类型

•主线程的堆栈信息

3.1发生anr的时间戳

查看mobilelog文件夹下的events_log,从日志中搜索关键字:am_anr,找到出现ANR的时间点、进程PID、ANR类型确定anr的时间戳。

3.2发生anr的进程号

3.3查看tracefile

-----pid21404 at 2011-04-0113:12:14 -----

3.4发生anr的进程包名

3.5查看tracefile

Cmdline: com.android.email

3.6发生anr的类型

Mobilelog的syslog中过滤anr in,找到anr in的日志,查看anrreason.

主线程的堆栈信息
查看trace file anr 进程的main thread回调栈
“main”(线程名) 
prio=5(进程号) 
tid=1(进程内部线程号) 
Runnable (线程状态)|
 group=“main”(线程组) sCount=0 dsCount=0 obj=0x73bcc7d0 self=0x7f20814c00 |
 sysTid=20176 (系统线程号) nice=-10 cgrp=default sched=0/0 handle=0x7f251349b0 | state=R schedstat=( 0 0 0 ) 
utm=12 stm=3 (  用户态/内核态的CPU时间(单位是jiffies) )
core=5 (该线程执行的cpu所在核)
HZ=100(1 jiffies  = 1000ms/100=10ms)
 | stack=0x7fdb75e000-0x7fdb760000 stackSize=8MB | held mutexes= "mutator lock"(shared held)
(堆栈调用信息,可以查看调用的关系,定位到具体位置)
 at ttt.push.InterceptorProxy.addMiuiApplication(InterceptorProxy.java:77) 
at ttt.push.InterceptorProxy.create(InterceptorProxy.java:59) 
at android.app.Activity.onCreate(Activity.java:1041) 
at miui.app.Activity.onCreate(SourceFile:47) 
at com.xxxx.moblie.ui.b.onCreate(SourceFile:172) 
at com.xxxx.moblie.ui.MainActivity.onCreate(SourceFile:68) 
at android.app.Activity.performCreate(Activity.java:7050) 
at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1214) 
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2807) 
at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2929) 
at android.app.ActivityThread.-wrap11(ActivityThread.java:-1) 
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1618) 
at android.os.Handler.dispatchMessage(Handler.java:105) 
at android.os.Looper.loop(Looper.java:171)
 at android.app.ActivityThread.main(ActivityThread.java:6699) 
at java.lang.reflect.Method.invoke(Native method) 
at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:246) 
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:783)

04 分析流程

file

file

APP is Idle:
检查CallStack,查看main thread的CallStack停在nativePollOnce (From SWT_JBT_TRACES)

No Focus Window ANR Check Point:
检查activity onResume时间点(此时activity能被看到),如果发生ANR时onResume还未完成,归类为APP Related Issue,否则进行步骤2判断:
异常case:the am_on_resume_called is called after ANR time// ANR Time (From Sys Log or SYS_ANDROID_LOG)
03-12 15:36:42.713   853   895 I WindowManager: Input event dispatching timed out sending to application AppWindowToken{f24f3cf token=Token{70fcbf5 ActivityRecord{1a714df u0 com.android.browser/.BrowserActivity t30}}}.  Reason: Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.
// onResume called (From Event Log)
03-12 15:36:54.024543  4616  4616 I am_on_resume_called: [0,com.android.browser.BrowserActivity]

检查relayout window时间,如果发生ANR时resume activity还未call relayout window,归类为APP Related Issue,否则为WMS Issue。
异常case:the resume activity call relayout window after ANR time
// onResume called(From Event Log or SYS_ANDROID_EVENT_LOG)
11-08 01:29:43.077073 20643 20643 I am_on_resume_called: [0,com.android.camera.CameraLauncher,LAUNCH_ACTIVITY]
// ANR time(From Sys Log or SYS_ANDROID_LOG)
11-08 01:29:45.769929   995  1155 I WindowManager: Input event dispatching timed out sending to application AppWindowToken{ddf4807 token=Token{d3fc2b1 ActivityRecord{e40f158 u0 com.mediatek.camera/com.android.camera.CameraLauncher t514}}}.  Reason: Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.
// relayout window called(From Sys Log or SYS_ANDROID_LOG)
11-08 01:29:45.895444   995  2093 I WindowManager: Relayout Window{599852d u0 com.mediatek.camera/com.android.camera.CameraLauncher}: oldVis=4 newVis=0 focusMayChange = true
11-08 01:29:46.034805   995  2087 W InputManager: Input event injection from pid 13134 timed out.

APP Related Issue一般处理流程:
1. 如果不是performance问题,请APP Owner参考“Call Stack Analysis”根据call stack进一步分析,常见问题同“常见SWT/ANR原因”。
2. 第三方APP问题,请使用最新版本软件和对比机进行对比验证,如果只有敝司平台手机能复现而对比机不能复现,请提交case同时注明“APPIOT” 关键字。3. 如果是Performance问题,建议先在user/user+root版本上复测,如仍能复现,请参考“Performance Check Point”进一步定位。