海马煲汤（五⼗⼆）Androidanr分析步骤总结
前⾔：最近经⼿了⽐较多的anr问题，声明经⼿不是解决，只是从log上推断造成anr的原因，以此作为根据转交给对应的⼈来处理。
1. ANR简介
ANR全名Application Not Responding, 也就是"应⽤⽆响应". 当操作在⼀段时间内系统⽆法处理时, 系统层⾯会弹出ANR对话框.
通常在如下⼏种种情况下会弹出ANR对话框:
5s内⽆法响应⽤户输⼊事件(例如键盘输⼊, 触摸屏幕等).
BroadcastReceiver的事件(onRecieve⽅法)在规定时间内没处理完(前台⼴播为10s，后台⼴播为60s)
rvice 前台20s后台200s未执⾏完成 Timeout executing rvice（Android O多了个startForeground 5s限制）
造成以上情况的⾸要原因就是在主线程(UI线程)⾥⾯做了太多的阻塞耗时操作, 例如⽂件读写, 数据库读写, ⽹络查询等等.（或者调⽤Thread.join/LockSupport.park/wait/sleep造成的阻塞）
具体定义：
framework/ba/rvices/core/java/com/android/rver/am/ActivityManagerService.java:
全国乙卷作文// How long we allow a receiver to run before giving up on it.
static final int BROADCAST_FG_TIMEOUT = 10*1000;
static final int BROADCAST_BG_TIMEOUT = 60*1000;
// How long we wait until we timeout on key dispatching.
static final int KEY_DISPATCHING_TIMEOUT = 5*1000;
framework/ba/rvices/core/java/com/android/rver/am/ActiveServices.java
// How long we wait for a rvice to finish executing.
static final int SERVICE_TIMEOUT = 20*1000;
// How long we wait for a rvice to finish executing.
static final int SERVICE_BACKGROUND_TIMEOUT = SERVICE_TIMEOUT * 10;
// calling startForeground() before we ANR + stop it.
static final int SERVICE_START_FOREGROUND_TIMEOUT = 5*1000;
2. ANR分析步骤
anr分析步骤我总结来看主要就如下5步。
2.1 events_log
查看event log确定anr时间点和发⽣anr的进程id
命令：grep "am_anr.*packageName" ./ -nri --include="events*"
⽐如：
06-22 23:15:36.257944 942 1021 I am_anr : [0,19721,com.android.chrome,-1463042491,Input dispatching timed out (Waiting to nd non-key event becau the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wa
it queue head age: 5508.0ms.)]
从上⾯log可以看出是com.android.chrome 在6-22 23:15:36发⽣了anr，所处进程id为19721
2.2 sys_log
查看sys_log确定当时系统各项占⽤，虽然我⼀直对百分⽐占⽤很没谱
命令：grep "anr in packageName" ./ -nri --include="sys_log*"
然后vim到对应⾏
⽐如：
06-22 23:15:42.121724 942 1021 I AnrManager: dumpStackTraces end!
06-22 23:15:42.159012 942 1021 I AnrManager: ANR in com.android.chrome (com.android.le.android.apps.chrome.Main), time=24007714 06-22 23:15:42.159012 942 1021 I AnrManager: Reason: Input dispatching timed out (Waiting to nd non-key event becau the touched window has not finish 06-22 23:15:42.159012 942 1021 I AnrManager: Load: 14.61 / 14.77 / 14.71
06-22 23:15:42.159012 942 1021 I AnrManager: Android time :[2018-06-22 23:15:42.12] [24013.623]
06-22 23:15:42.159012 942 1021 I AnrManager: CPU usage from 83364ms to 43ms ago (2018-06-22 23:14:12.849 to 2018-06-22 23:15:36.170):
06-22 23:15:42.159012 942 1021 I AnrManager: 68% 942/system_rver: 50% ur + 17% kernel / faults: 267589 minor 3994 major
06-22 23:15:42.159012 942 1021 I AnrManager: 21% 1715/com.android.systemui: 16% ur + 5.5% kernel / faults: 133310 minor 4496 major
我们可以注意到sys_log时间点晚了不少
2.
<主要是来确定下发⽣anr的时候的堆栈，如果打印出耗时操作的堆栈肯定最好了
发⽣anr后导出⼿机⾥/data/anr下的⽂件，⽂件名称⼀般是这样的“anr_2018-06-22-17-42-44-420”，之前我们通过events_log确
定了anr发⽣时间，这时通过时间找对应⽂件。祭祖祭文
⽐如上⾯举的chrome例⼦：anr_2018-06-22-23-15-36-796 这个⽂件所对应的时间是差不多的，打开瞅⼀下。
----- pid 19721 at 2018-06-22 23:15:36 -----
Cmd line: com.android.chrome
前两⾏ pid 19721对的上，时间时分秒对的上，包名com.android.chrome对的上。
"main" prio=5 tid=1 Waiting
| group="main" sCount=1 dsCount=0 flags=1 obj=0x725815f0 lf=0xeb15b000
| sysTid=19721 nice=-4 cgrp=default sched=0/0 handle=0xef2134a4
| state=S schedstat=( 1948839680 121430176 1126 ) utm=134 stm=60 core=7 HZ=100
| stack=0xff29c000-0xff29e000 stackSize=8MB
| held mutexes=
at java.lang.Object.wait(Native method)
- waiting on <0x064cfca3> (a java.lang.Object)
at java.lang.Thread.parkFor$(Thread.java:2137)
- locked <0x064cfca3> (a java.lang.Object)
at sun.misc.Unsafe.park(Unsafe.java:358)
at urrent.locks.LockSupport.park(LockSupport.java:190)
at urrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:868)
at urrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1021)
at urrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1328)
at urrent.CountDownLatch.await(CountDownLatch.java:232)
at ponents.GoogleAccounts(AccountManagerFacade.java:37)
at ponents.GetGoogleAccounts(AccountManagerFacade.java:47)
at ponents.GetGoogleAccountNames(AccountManagerFacade.java:30)
at org.chromium.chrome.browr.ChromeTabbedActivity.finishNativeInitialization(ChromeTabbedActivity.java:158)
at org.chromium.chrome.browr.init.ChromeBrowrInitializer$9.run(ChromeBrowrInitializer.java:3)
at org.chromium.chrome.browr.init.ChainedTasks$1.run(ChainedTasks.java:7)
at android.os.Handler.handleCallback(Handler.java:790)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loop(Looper.java:168)
at android.app.ActivityThread.main(ActivityThread.java:6555)
at flect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:438)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:857)
从堆栈来看是由于chrome调⽤getGoogleAccounts继⽽调⽤到LockSupport.park-->Object.wait，导致UI线程⼀直在等待造成anr。（这⾥其实不严谨，没有直接log作证，万⼀⼈家刚wait没多久只是之前⼀个操作耗时长呢）
由于没有chrome代码，这个故障只好不了了之了，但从堆栈可以看到有可能是哪个模块没有及时调⽤LockSupport.unpark导致的anr，这样就到应⽤级别了，需要应⽤继续往下看。
2.4 main_log
开题答辩开场白
main_log主要是针对应⽤的log打印的，但有时候追溯问题还是会回到sys_log，主要看是阻塞在应⽤层还是framework或者native 驱动都说不准。
anr主要是发⽣在应⽤的主线程即Ui线程中，那么main_log⾥搜索对应的 线程号=进程号的log看下。
⽐如上⾯的chrome搜索：grep " 19721 19721 " ./ -nr --include="main*"
时间点关注：6-22 23:15:30 - 23:15:36 左右的log，毕竟主要是这5s导致的anr
2.5 综合考虑
其实中打印的堆栈有可能是主要原因，有可能是次要原因，也有可能只是个躺枪的，毕竟anr的时间段，就以点击事件anr 5s为例，5s点下去了各个⽅法都会有耗时，如果⼀个⽅法占⽤了1s，另外⼀个占⽤了3s多，最后的⼀个⽅法刚开始执⾏anr就把他堆栈打印出来了那不是很冤。
日本人体摄影
如果有条件当然是从各种log推断各个⽅法分别耗时多少，然后综合评判哪个⽅法可以优化，哪个⽅法由于外部原因不可避免的耗时延长这都是要看下的。
关东煮做法另外原因也分直接原因和根本原因，⽐如直接原因是主线程wait了，那根本原因看下是谁让他wait或者谁没及时notify呢。
3. 总结最终痴女电车
anr的问题如果堆栈打印的很明⽩，log⾥也有对应证据，那还是很好的，就怕anr 好⼏个⽅法都贡献点延迟，log没有，想调试的话anr⼀般是monkey中跑出来的，调试难度⽐较⼤，那真是欲仙欲死。
本地免log调试可以参考：
自然选择学说
