目录

一、ANR出的问题原因

二、日志分析

2.1 CPU 负载

2.2 内存

2.3 堆栈信息

三、案例分析

3.1 主线程无卡顿，处于正常状态堆栈

3.2 主线程执行耗时操作

3.3 主线程被锁阻塞

3.4 CPU被抢占

3.5 内存紧张导致ANR

3.6 系统服务超时导致ANR

3.7 Input dispatching timed out

---

一、ANR出的问题原因

很多开发者认为，ANR就是耗时操作导致，全部是app应用层的问题。实际上，线上环境大部分ANR由系统原因导致。

应用层导致ANR（耗时操作）
1、函数阻塞：如死循环、主线程IO、处理大数据
2、锁出错：主线程等待子线程的锁
3、内存紧张：系统分配给一个应用的内存是有上限的，长期处于内存紧张，会导致频繁内存交换，进而导致应用的一些操作超时

系统导致ANR
1、CPU被抢占：一般来说，前台在玩游戏，可能会导致你的后台广播被抢占CPU
2、系统服务无法及时响应：比如获取系统联系人等，系统的服务都是Binder机制，服务能力也是有限的，有可能系统服务长时间不响应导致ANR
3、其他应用占用的大量内存

二、日志分析

2.1 CPU 负载

如上所示：

第一行：表明负载信息抓取在ANR发生之后的0~28360ms。同时也指明了ANR的时间点：2024-02-29 13:11:00.095

中间部分：各个进程占用的CPU的详细情况

最后一行：各个进程合计占用的CPU信息。

a. user:用户态,kernel:内核态
b. faults:内存缺页，minor——轻微的，major——重度，需要从磁盘拿数据
c. iowait:IO使用（等待）占比
d. irq:硬中断，softirq:软中断

iowait占比很高，意味着有很大可能，是io耗时导致ANR，具体进一步查看有没有进程faults major比较多。

单进程CPU的负载并不是以100%为上限，而是有几个核，就有百分之几百，如4核上限为400%。

2.2 内存

从含义可以得出结论：Free memory until OOME 的值很小的时候，已经处于内存紧张状态。应用可能是占用了过多内存。
ps:如果ANR时间点前后，日志里有打印onTrimMemory，也可以作为内存紧张的一个参考判断

2.3 堆栈信息

堆栈信息是最重要的一个信息，展示了ANR发生的进程当前所有线程的状态。

如上日志所示，本文截图了两个线程信息，一个是主线程main，它的状态是native。
另一个是OkHttp ConnectionPool，它的状态是TimeWaiting。众所周知，教科书上说线程状态有5种：新建、就绪、执行、阻塞、死亡。而Java中的线程状态有6种，6种状态都定义在：java.lang.Thread.State中

问题来了，上述main线程的native是什么状态，哪来的？
其实trace文件中的状态是是CPP代码中定义的状态，下面是一张对应关系表。

由此可知，main函数的native状态是正在执行JNI函数。堆栈信息是我们分析ANR的第一个重要的信息，一般来说：
main线程处于 BLOCK、WAITING、TIMEWAITING状态，那基本上是函数阻塞导致ANR；
如果main线程无异常，则应该排查CPU负载和内存环境。

三、案例分析

3.1 主线程无卡顿，处于正常状态堆栈

上述主线程堆栈就是一个很正常的空闲堆栈，表明主线程正在等待新的消息。
如果ANR日志里主线程是这样一个状态，那可能有两个原因：

遇到这种空闲堆栈，可以按照第2章的方法去分析CPU、内存的情况。其次可以关注抓取日志的时间和ANR发生的时间是否相隔过久，时间过久这个堆栈就没有分析意义了。

3.2 主线程执行耗时操作

上述日志表明，主线程正处于执行状态，看堆栈信息可知不是处于空闲状态，发生ANR是因为一处click监听函数里执行了耗时操作。

3.3 主线程被锁阻塞

这是一个典型的主线程被锁阻塞的例子；
其中等待的锁是<0x01aed1da>，这个锁的持有者是线程 3。进一步搜索 “tid=3” 找到线程3， 发现它正在TimeWating。
那么ANR的原因找到了：线程3持有了一把锁，并且自身长时间不释放，主线程等待这把锁发生超时。在线上环境中，常见因锁而ANR的场景是SharePreference写入。

3.4 CPU被抢占

如上日志，第二行是钉钉的进程，占据CPU高达543%，抢占了大部分CPU资源，因而导致发生ANR。

3.5 内存紧张导致ANR

如果有一份日志，CPU和堆栈都很正常（不贴出来了），仍旧发生ANR，考虑是内存紧张。
从CPU第一行信息可以发现，ANR的时间点是2020-10-31 22:38:58.468—CPU usage from 0ms to 21752ms later (2020-10-31 22:38:58.468 to 2020-10-31 22:39:20.220)
接着去logcat里搜索am_meminfo， 这个没有搜索到。再次搜索onTrimMemory，果然发现了很多条记录；

可以看出，在发生ANR的时间点前后，内存都处于紧张状态，level等级是80，查看Android API 文档；
可知80这个等级是很严重的，应用马上就要被杀死，被杀死的这个应用从名字可以看出来是桌面，连桌面都快要被杀死，那普通应用能好到哪里去呢？
一般来说，发生内存紧张，会导致多个应用发生ANR，所以在日志中如果发现有多个应用一起ANR了，可以初步判定，此ANR与你的应用无关。

3.6 系统服务超时导致ANR

系统服务超时一般会包含BinderProxy.transactNative关键字，请看如下日志：

以上可以看出来，是在从堆栈可以看出ANR：getExternalFilesDirs。

可以看出来是在AMS创建APP时出现的问题，因此可以给系统侧分析。

3.7 Input dispatching timed out

ANR部分日志信息：
PID: 32640
UID: 1110155
Input dispatching timed out (4e4035c com.aaa/com.aaa.home.MainActivity (server) is not responding. Waited 5001ms for MotionEvent(deviceId=-1, eventTime=85286596000000, source=0x00001002, displayId=0, action=DOWN, actionButton=0x00000000, flags=0x00000000, metaState=0x00000000, buttonState=0x00000000, classification=NONE, edgeFlags=0x00000000, xPrecision=1.0, yPrecision=1.0, xCursorPosition=nan, yCursorPosition=nan, pointers=[0: (525.0, 957.0)]), policyFlags=0x6b000000)

CPU usage from 0ms to 31081ms later (2024-10-22 07:03:11.876 to 2024-10-22 07:03:42.956):

这个导致的原因有很多，这个问题无法从ANR日志里去分析，就需要从系统日志里去查找问题，这个报错的时间上，需要往前去找日志信息，从日志里可以找到关键的信息，如下

10-22 07:03:07.795 17729 17830 I InputDispatcher: Not sending touch event to 4e4035c com.aaa/com.aaa.home.MainActivity because it is paused

点击事件没有发送成功，说明这里就是发生问题的关键时间点，顺藤摸瓜，往上找一下有没有什么错误信息，
10-22 07:03:07.634 1015 15113 D EMS:ExceptionHandlerFactory: Get handler : STRICT_MODE
10-22 07:03:07.634 1015 15113 E JavaBinder: *** Uncaught remote exception! (Exceptions are not yet supported across processes.)
10-22 07:03:07.634 1015 15113 E JavaBinder: java.util.concurrent.RejectedExecutionException: Task c.a.a.a.u@4f72b0e rejected from java.util.concurrent.ThreadPoolExecutor@735f423[Running, pool size = 8, active threads = 8, queued tasks = 6, completed tasks = 19620]
10-22 07:03:07.634 1015 15113 E JavaBinder: at java.util.concurrent.ThreadPoolExecutorA b o r t P o l i c y . r e j e c t e d E x e c u t i o n ( T h r e a d P o o l E x e c u t o r . j a v a : 2086 ) 10 − 2207 : 03 : 07.634101515113 E J a v a B i n d e r : a t j a v a . u t i l . c o n c u r r e n t . T h r e a d P o o l E x e c u t o r . r e j e c t ( T h r e a d P o o l E x e c u t o r . j a v a : 848 ) 10 − 2207 : 03 : 07.634101515113 E J a v a B i n d e r : a t j a v a . u t i l . c o n c u r r e n t . T h r e a d P o o l E x e c u t o r . e x e c u t e ( T h r e a d P o o l E x e c u t o r . j a v a : 1394 ) 10 − 2207 : 03 : 07.634101515113 E J a v a B i n d e r : a t c . a . a . a . v . a ( U n k n o w n S o u r c e : 2 ) 10 − 2207 : 03 : 07.634101515113 E J a v a B i n d e r : a t c . a . a . a . t . p ( U n k n o w n S o u r c e : 104 ) 10 − 2207 : 03 : 07.634101515113 E J a v a B i n d e r : a t c . a . a . a . t . j ( U n k n o w n S o u r c e : 102 ) 10 − 2207 : 03 : 07.634101515113 E J a v a B i n d e r : a t c . b . a . b AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2086) 10-22 07:03:07.634 1015 15113 E JavaBinder: at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:848) 10-22 07:03:07.634 1015 15113 E JavaBinder: at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1394) 10-22 07:03:07.634 1015 15113 E JavaBinder: at c.a.a.a.v.a(Unknown Source:2) 10-22 07:03:07.634 1015 15113 E JavaBinder: at c.a.a.a.t.p(Unknown Source:104) 10-22 07:03:07.634 1015 15113 E JavaBinder: at c.a.a.a.t.j(Unknown Source:102) 10-22 07:03:07.634 1015 15113 E JavaBinder: at c.b.a.bAbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2086)10−2207:03:07.634101515113EJavaBinder:atjava.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:848)10−2207:03:07.634101515113EJavaBinder:atjava.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1394)10−2207:03:07.634101515113EJavaBinder:atc.a.a.a.v.a(UnknownSource:2)10−2207:03:07.634101515113EJavaBinder:atc.a.a.a.t.p(UnknownSource:104)10−2207:03:07.634101515113EJavaBinder:atc.a.a.a.t.j(UnknownSource:102)10−2207:03:07.634101515113EJavaBinder:atc.b.a.ba.onTransact(Unknown Source:207)
10-22 07:03:07.634 1015 15113 E JavaBinder: at android.os.Binder.execTransactInternal(Binder.java:1179)
10-22 07:03:07.634 1015 15113 E JavaBinder: at android.os.Binder.execTransact(Binder.java:1143)

1015进程频繁过量使用binder线程导致系统Binder线程池满载, 带来后果就是系统做binder进程通讯变慢亦或停止，界面点击响应不及时

如下图: 1015进程频繁抛出RejectedExcutionException, 该进程频繁进行binder进程间通信，使得系统binder线程池满载(Runing 8个+ active 8个共计16个)，导致其他程序在和system_server进程间通信过程中存在等待延迟，拖慢点击事件响应而出现ANR。