Android ANR日志分析进行曲

定义

ANR(Application Not Responding) 应用程序无响应。如果你应用程序在UI线程被阻塞太长时间，就会出现ANR，通常出现ANR，系统会弹出一个提示提示框，让用户知道，该程序正在被阻塞，是否继续等待还是关闭。

ANR出现的原因

1:主线程频繁进行耗时的IO操作：如数据库读写（UI线程等待其它线程释放某个锁，导致UI线程无法处理用户输入）；
2:多线程操作的死锁，主线程被block；
3:主线程被Binder 对端block；
4:System Server中WatchDog出现ANR；
5:service binder的连接达到上线无法和SystemServer通信
6:系统资源已耗尽（管道、CPU、IO）

ANR类型

出现ANR的一般有以下几种类型：
1:KeyDispatchTimeout（常见）
input事件在5S内没有处理完成发生了ANR。
logcat日志关键字：Input event dispatching timed out

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

3:ServiceTimeout
前台Service：onCreate，onStart，onBind等生命周期在20s内没有处理完成发生ANR。
后台Service：onCreate，onStart，onBind等生命周期在200s内没有处理完成发生ANR
logcat日志关键字：Timeout executing service

4：ContentProviderTimeout
ContentProvider 在10S内没有处理完成发生ANR。 logcat日志关键字：timeout publishing content providers

ANR分析过程

查看events_log

在android stuido Terminal面板，输出events日志信息，命令如下：

adb logcat -b events

面板信息如下：

其次Terminal面板找到关键字：am_anr，找到出现ANR的时间点、进程PID、ANR类型。

从上面的log我们可以看出：应用com.example.myapplication在09-25 23:04:27.355时间，发生了一次KeyDispatchTimeout类型的ANR，它的进程号是3724. 把关键的信息整理一下：
ANR时间：09-25 23:04:27.355

进程pid：3879
进程名：com.example.myapplication
ANR类型：KeyDispatchTimeout

通过上面关键信息，我们了解到，发生KeyDispatchTimeout的ANR是因为input事件在5秒内没有处理完成。那么在这个时间09-25 23:04:27.355的前5秒，也就是（23:04:22 ~23:04:23）时间段左右程序到底做了什么事情？我们已经知道pid了，再搜索一下pid = 3879的日志.这些日志表示该进程所运行的轨迹，关键的日志如下：

仔细看一下就会发现：

23:04:19时间点做了界面跳转，之后将近8秒后，就出现ANR了，那么，我们知道怎么开始的，但是具体原因还是没有找到。

那么接下来，是不是当时CPU很紧张、各路APP再抢占资源？我们再看看CPU的信息,。搜索关键字关键字： ANR IN

2021-09-26 07:04:28.043 1597-1611/system_process E/ActivityManager: ANR in com.example.myapplication (com.example.myapplication/.activities.ANRTestActivity)PID: 3879Reason: Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length:  Wait queue head age: 5706.6ms.)Load: 0.23 / 0.09 / 0.07CPU usage from 507882ms to 0ms ago (2021-09-25 14:56:16.323 to 2021-09-25 23:04:27.351):0.9% 1597/system_server: 0.1% user + 0.7% kernel / faults: 26762 minor 1 major0.2% 1800/com.android.settings: 0% user + 0.2% kernel / faults: 8985 minor 8 major0.6% 1303/surfaceflinger: 0% user + 0.6% kernel / faults: 18 minor0.1% 2094/com.google.android.apps.nexuslauncher: 0% user + 0.1% kernel / faults: 1130 minor 2 major0% 1692/com.android.systemui: 0% user + 0% kernel / faults: 381 minor0% 1320/audioserver: 0% user + 0% kernel / faults: 38 minor0% 2214/com.google.android.googlequicksearchbox:search: 0% user + 0% kernel / faults: 4059 minor0% 2000/com.google.android.gms.persistent: 0% user + 0% kernel / faults: 947 minor0% 1779/com.android.phone: 0% user + 0% kernel / faults: 110 minor0% 2274/com.google.android.gms: 0% user + 0% kernel / faults: 542 minor 20 major0% 1307/adbd: 0% user + 0% kernel / faults: 2411 minor0% 1252/logd: 0% user + 0% kernel / faults: 40 minor0% 1329/netd: 0% user + 0% kernel / faults: 153 minor0% 4/kworker/0:0: 0% user + 0% kernel0% 2108/com.android.printspooler: 0% user + 0% kernel / faults: 878 minor0% 2141/com.google.process.gapps: 0% user + 0% kernel / faults: 448 minor0% 2873/com.google.android.gms.unstable: 0% user + 0% kernel / faults: 156 minor0% 1250/jbd2/vdc-8: 0% user + 0% kernel0% 3/ksoftirqd/0: 0% user + 0% kernel0% 8/rcu_preempt: 0% user + 0% kernel0% 1241/kworker/0:1H: 0% user + 0% kernel0% 1302/servicemanager: 0% user + 0% kernel0% 1319/zygote: 0% user + 0% kernel / faults: 560 minor0% 1330/rild: 0% user + 0% kernel0% 6/kworker/u8:0: 0% user + 0% kernel0% 679/kworker/1:1: 0% user + 0% kernel0% 680/kworker/2:1: 0% user + 0% kernel0% 681/kworker/3:1: 0% user + 0% kernel0% 1299/healthd: 0% user + 0% kernel0% 1301/lmkd: 0% user + 0% kernel0% 1331/fingerprintd: 0% user + 0% kernel+0% 3879/com.example.myapplication: 0% user + 0% kernel+0% 3926/com.android.calendar: 0% user + 0% kernel+0% 3939/com.android.providers.calendar: 0% user + 0% kernel+0% 3960/com.android.deskclock: 0% user + 0% kernel+0% 4019/logcat: 0% user + 0% kernel0.3% TOTAL: 0% user + 0.3% kernel + 0% iowait + 0% softirqCPU usage from 183ms to 689ms later (2021-09-25 23:04:27.534 to 2021-09-25 23:04:28.040):
0% TOTAL: 0% user + 0% kernel

从上面可以看出，各路进程CPU占用基本低于1%，显然不是CPU负载的原因了。那么到底是什么原因呢？这时就要看我们的终极大杀器——traces.txt。

2.traces.txt日志分析

我们需要把traces.txt导出来，操作命令如下图：

通过traces文件,我们可以拿到线程名、堆栈信息、线程当前状态、binder call等信息。通过adb命令拿到该文件：adb pull /data/anr/traces.txt

接下来，我们需要把traces.txt导入AS，如下：

traces.txt里面的一些字段，看看它到底能给我们提供什么信息.
main：main标识是主线程，如果是线程，那么命名成“Thread-X”的格式,x表示线程id,逐步递增。
prio：线程优先级,默认是5
tid：tid不是线程的id，是线程唯一标识ID
group：是线程组名称
sCount：该线程被挂起的次数
dsCount：是线程被调试器挂起的次数
obj：对象地址
self：该线程Native的地址
sysTid：是线程号(主线程的线程号和进程号相同)
nice：是线程的调度优先级
sched：分别标志了线程的调度策略和优先级
cgrp：调度归属组
handle：线程处理函数的地址。
state：是调度状态
schedstat：从/proc/[pid]/task/[tid]/schedstat读出，三个值分别表示线程在cpu上执行的时间、线程的等待时间和线程执行的时间片长度，不支持这项信息的三个值都是0；
utm：是线程用户态下使用的时间值(单位是jiffies）
stm：是内核态下的调度时间值
core：是最后执行这个线程的cpu核的序号。

Java的堆栈信息是我们最关心的，它能够定位到具体位置。从上面的traces,我们可以判断com.example.myapplication.activities.ANRTestActivity$1.onClick(ANRTestActivity.java:25)点击之后导致了com.example.myapplication发生了ANR。在第25行代码，如下：

从上面源码可以看出，点击事件里面的方法休眠了15秒，导致Input不能及时处理引发ANR。

总结一下这分析流程：首先我们搜索am_anr，找到出现ANR的时间点、进程PID、ANR类型、然后再找搜索PID，找前5秒左右的日志。过滤ANR IN 查看CPU信息，接着查看traces.txt，找到java的堆栈信息定位代码位置，最后查看源码，分析与解决问题。这个过程基本能找到发生ANR的来龙去脉。

小伙伴如果有兴趣的话，欢迎来阅读Android ListView性能优化案例这篇文章，关注公众号即可阅读此文章，感谢关注。

Android ANR日志分析进行曲相关推荐

转 android anr 分析示例,[摘]Android ANR日志分析指南之实例解析
前文<[摘]Android ANR日志分析指南>也摘抄了如何分析,接下来通过实例解析. 一.主线程被其他线程lock,导致死锁 waiting on <0x1cd570> (a ...
Android ANR日志分析指南，android查看网络请求和响应
既然不是CPU负载的原因,那么到底是什么原因呢? 这时就要看我们的终极大杀器--traces.txt. 二. traces.txt 日志分析当APP不响应.响应慢了.或者WatchDog的监视没有得 ...
Android debuglogger日志分析-自动重启
大家有没有遇到和我一样的问题,android设备(我这里android 平板)用着用着突然就黑屏自动重启了,重启后一切正常,这个问题还是概率性的,复现都不好复现... 本人公司是做平板定制的,主要针对 ...
Android ANR 实例分析
什么是ANR? 以下四个条件都可以造成ANR发生: InputDispatching Timeout:5秒内无法响应屏幕触摸事件或键盘输入事件 BroadcastQueue Timeout :在执行前 ...
Android错误日志分析
Android Studio下常见异常以及分析方法常见异常 NullPointerException 原因:调用对象的方法或属性,但对象为空. ClassCastException 原因:类型转换异 ...
Android ANR问题分析
从事andriod系统开发以来接触了不少crash相关的问题,对于Crash分为Framework/App Crash, Native Crash,以及Kernel Crash 对于他们的解释对于f ...
【Android】如何分析 ANR 日志
前言前两天,我已经写了一篇文章对 ANR 的产生原理进行了简单的探讨,链接如下: [Android]ANR 原理解析感兴趣的大佬可以前去观摩观摩,今天这篇文章,将写写如何进行 ANR 日志的分析. ...
Android ANR分析-笔记
1.什么是ANR ANR:Application Not Responding,即应用无响应 2.ANR的类型 1.KeyDispatchTimeout(5 seconds).按键或触摸事件在5s内无 ...
你真的会解决android ANR 问题吗？
前言还记得之前写过一篇关于ANR 的介绍,现在看来,那个只是皮毛.现实中遇到应用或系统ANR 的问题,是很难解决的.下面进入正题,来详细了解下如何解决. 一. ANR 分析步骤 Log分析: 1 ...

Android ANR日志分析进行曲

Android ANR日志分析进行曲相关推荐

最新文章

热门文章