ANR 和 产生场景

ANR(Application Not responding),是指应用程序未响应,Android系统对于一些事件需要在一定的时间范围内完
成,如果超过预定时间能未能得到有效响应或者响应时间过长,都会造成ANR
在 Android 里,应用程序的响应性是由 Activity Manager 和 WindowManager 系统服务监视的。当它监测到以下
情况中的一个时,Android 就会针对特定的应用程序显示 ANR:

场景

  • Service Timeout
  • BroadcastQueue Timeout
  • ContentProvider Timeout
  • InputDispatching Timeout

Timeout时长

  • 对于前台服务,则超时为SERVICE_TIMEOUT = 20s;
  • 对于后台服务,则超时为SERVICE_BACKGROUND_TIMEOUT = 200s
  • 对于前台广播,则超时为BROADCAST_FG_TIMEOUT = 10s;
  • 对于后台广播,则超时为BROADCAST_BG_TIMEOUT = 60s;
  • ContentProvider超时为CONTENT_PROVIDER_PUBLISH_TIMEOUT = 10s;
    InputDispatching Timeout: 输入事件分发超时5s,包括按键和触摸事件。

注意事项: Input的超时机制与其他的不同,对于input来说即便某次事件执行时间超过timeout时长,只要用 户后续在没有再生成输入事件,则不会触发ANR

超时检测机制

  1. Service超时检测机制:
    超过一定时间没有执行完相应操作来触发移除延时消息,则会触发anr;
  2. BroadcastReceiver超时检测机制:
    有序广播的总执行时间超过 2* receiver个数 * timeout时长,则会触发anr;
    有序广播的某一个receiver执行过程超过 timeout时长,则会触发anr;
  3. 另外:
    对于Service, Broadcast, Input发生ANR之后,最终都会调用AMS.appNotResponding;
    对于provider,在其进程启动时publish过程可能会出现ANR, 则会直接杀进程以及清理相应信息,而不会弹 出ANR的对话框

如何避免 ANR?

考虑上面的 ANR 定义,让我们来研究一下为什么它会在 Android 应用程序里发生和如何最佳 构建应用程序来避免 ANR。

  • Android 应用程序通常是运行在一个单独的线程(例如,main)里。这意味着你的应用程序 所做的事情如果在主线程里占用了太长的时间的话,就会引发 ANR 对话框,因为你的应用程 序并没有给自己机会来处理输入事件或者 Intent 广播。

  • 因此,运行在主线程里的任何方法都尽可能少做事情。特别是,Activity 应该在它的关键 生命周期方法(如 onCreate()和 onResume())里尽可能少的去做创建操作。潜在的耗时操 作,例如网络或数据库操作,或者高耗时的计算如改变位图尺寸,应该在子线程里(或者以 数据 库操作为例,通过异步请求的方式)来完成。然而,不是说你的主线程阻塞在那里等 待子线程的完成——也不是调用 Thread.wait()或是 Thread.sleep()。替代的方法是,主 线程应该为子线程提供一个 Handler,以便完成时能够提交给主线程。以这种方式设计你的 应用程序,将 能保证你的主线程保持对输入的响应性并能避免由于 5 秒输入事件的超时引 发的 ANR 对话框。这种做法应该在其它显示 UI 的线程里效仿,因为它们都受相同的超 时影 响。

  • 因此,运行在主线程里的任何方法都尽可能少做事情。特别是,Activity 应该在它的关键 生命周期方法(如 onCreate()和 onResume())里尽可能少的去做创建操作。潜在的耗时操 作,例如网络或数据库操作,或者高耗时的计算如改变位图尺寸,应该在子线程里(或者以 数据 库操作为例,通过异步请求的方式)来完成。然而,不是说你的主线程阻塞在那里等 待子线程的完成——也不是调用 Thread.wait()或是 Thread.sleep()。替代的方法是,主 线程应该为子线程提供一个 Handler,以便完成时能够提交给主线程。以这种方式设计你的 应用程序,将 能保证你的主线程保持对输入的响应性并能避免由于 5 秒输入事件的超时引 发的 ANR 对话框。这种做法应该在其它显示 UI 的线程里效仿,因为它们都受相同的超 时影 响。

  • 增强响应灵敏性
    一般来说,在应用程序里,100 到 200ms 是用户能感知阻滞的时间阈值。因此,这里有一些 额外的技巧来避免 ANR,并有助于让你的应用程序看起来有响应性。 如果你的应用程序为响应用户输入正在后台工作的话,可以显示工作的进度(ProgressBar 和 ProgressDialog 对这种情况来说很有用)。
    特别是游戏,在子线程里做移动的计算。

如果你的应用程序有一个耗时的初始化过程的话,考虑可以显示一个 SplashScreen 或者快 速显示主画面并异步来 填充这些信息。在这两种情况下,你都应该显示正在进行的进度,以 免用户认为应用程序被冻结了。

前台与后台ANR

  • 前台ANR:用户能感知,比如拥有前台可见的activity的进程,或者拥有前台通知的fg-service的进程,此时发 生ANR对用户体验影响比较大,需要弹框让用户决定是否退出还是等待
  • 后台ANR:,只抓取发生无响应进程的trace,也不会收集CPU信息,并且会在后台直接杀掉该无响应的进 程,不会弹框提示用户

ANR分析

  1. 前台ANR发生后,系统会马上去抓取现场的信息,用于调试分析,收集的信息如下:
  • 将am_anr信息输出到EventLog,也就是说ANR触发的时间点最接近的就是EventLog中输出的am_anr信 息
  • 收集以下重要进程的各个线程调用栈trace信息,保存在data/anr/traces.txt文件
    **当前发生ANR的进程,system_server进程以及所有persistent进程
    **audioserver, cameraserver, mediaserver, surfaceflinger等重要的native进程
    **CPU使用率排名前5的进程
  • 将发生ANR的reason以及CPU使用情况信息输出到main log
  • 将traces文件和CPU使用情况信息保存到dropbox,即data/system/dropbox目录
  • 对用户可感知的进程则弹出ANR对话框告知用户,对用户不可感知的进程发生ANR则直接杀掉
  1. 分析步骤
    1. 定位发生ANR时间点
    1. 查看trace信息
    1. 分析是否有耗时的message,binder调用,锁的竞争,CPU资源的抢占 4. 结合具体的业务场景的上下文来分析

如何避免ANR发生

  1. 主线程尽量只做UI相关的操作,避免耗时操作,比如过度复杂的UI绘制,网络操作,文件IO操作;
  2. 避免主线程跟工作线程发生锁的竞争,减少系统耗时binder的调用,谨慎使用sharePreference,注意主线程
    执行provider query操作

总之,尽可能减少主线程的负载,让其空闲待命,以期可随时响应用户的操作

trace.txt文件解读

  1. 人为的收集trace.txt的命令
    adb shell kill -3 888 //可指定进程pid

执行完该命令后traces信息的结果保存到文件/data/anr/traces.txt

  1. trace文件解读
----- pid 888 at 2016-11-11 22:22:22 ----- Cmd line: system_server
ABI: arm
Build type: optimized
Zygote loaded classes=4113 post zygote classes=3239
Intern table: 57550 strong; 9315 weak
JNI: CheckJNI is off; globals=2418 (plus 115 weak)
Libraries: /system/lib/libandroid.so /system/lib/libandroid_servers.so /system/lib/libaudioeffect_jni.so /system/lib/libcompiler_rt.so /system/lib/libjavacrypto.so /system/lib/libjnigraphics.so /system/lib/libmedia_jni.so /system/lib/librs_jni.so /system/lib/libsechook.so /system/lib/libshell_jni.so /system/lib/libsoundpool.so /system/lib/libwebviewchromium_loader.so /system/lib/libwifi-service.so /vendor/lib/libalarmservice_jni.so /vendor/lib/liblocationservice.so libjavacore.so (16) //已分配堆内存大小40MB,其中29M已用,总分配207772个对象
Heap: 27% free, 29MB/40MB; 307772 objects ... //省略GC相关信息
//当前进程总99个线程
DALVIK THREADS (99): //主线程调用栈
"main" prio=5 tid=1 Native
| group="main" sCount=1 dsCount=0 obj=0x75bd9fb0 self=0x5573d4f770
| sysTid=12078 nice=-2 cgrp=default sched=0/0 handle=0x7fa75fafe8
| state=S schedstat=( 5907843636 827600677 5112 ) utm=453 stm=137 core=0 HZ=100 | stack=0x7fd64ef000-0x7fd64f1000 stackSize=8MB
| held mutexes=
//内核栈
kernel: __switch_to+0x70/0x7c
  
kernel: SyS_epoll_wait+0x2a0/0x324
kernel: SyS_epoll_pwait+0xa4/0x120
kernel: cpu_switch_to+0x48/0x4c
native: #00 pc 0000000000069be4
native: #01 pc 000000000001cca4
native: #02 pc 000000000001ad74
native: #03 pc 000000000001b154
/system/lib64/libc.so (__epoll_pwait+8)
/system/lib64/libc.so (epoll_pwait+32) /system/lib64/libutils.so (_ZN7android6Looper9pollInnerEi+144) /system/lib64/libutils.so
(_ZN7android6Looper8pollOnceEiPiS1_PPv+80)
native: #04 pc 00000000000d4bc0 /system/lib64/libandroid_runtime.so
(_ZN7android18NativeMessageQueue8pollOnceEP7_JNIEnvP8_jobjecti+48)
native: #05 pc 000000000000082c /data/dalvik-cache/arm64/system@framework@boot.oat
(Java_android_os_MessageQueue_nativePollOnce__JI+144)
at android.os.MessageQueue.nativePollOnce(Native method)
at android.os.MessageQueue.next(MessageQueue.java:323)
at android.os.Looper.loop(Looper.java:135)
at com.android.server.SystemServer.run(SystemServer.java:290)
at com.android.server.SystemServer.main(SystemServer.java:175)
at java.lang.reflect.Method.invoke!(Native method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:738) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:628)
"Binder_1" prio=5 tid=8 Native
| group="main" sCount=1 dsCount=0 obj=0x12c610a0 self=0x5573e5c750
| sysTid=12092 nice=0 cgrp=default sched=0/0 handle=0x7fa2743450
| state=S schedstat=( 796240075 863170759 3586 ) utm=50 stm=29 core=1 HZ=100 | stack=0x7fa2647000-0x7fa2649000 stackSize=1013KB
| held mutexes=
kernel: __switch_to+0x70/0x7c
kernel: binder_thread_read+0xd78/0xeb0
kernel: binder_ioctl_write_read+0x178/0x24c
kernel: binder_ioctl+0x2b0/0x5e0
kernel: do_vfs_ioctl+0x4a4/0x578
kernel: SyS_ioctl+0x5c/0x88
kernel: cpu_switch_to+0x48/0x4c
native: #00 pc 0000000000069cd0 /system/lib64/libc.so (__ioctl+4)
native: #01 pc 0000000000073cf4 /system/lib64/libc.so (ioctl+100)
native: #02 pc 000000000002d6e8 /system/lib64/libbinder.so
(_ZN7android14IPCThreadState14talkWithDriverEb+164)
native: #03 pc 000000000002df3c /system/lib64/libbinder.so
(_ZN7android14IPCThreadState20getAndExecuteCommandEv+24) native: #04 pc 000000000002e114 /system/lib64/libbinder.so
(_ZN7android14IPCThreadState14joinThreadPoolEb+124)
native: #05 pc 0000000000036c38 /system/lib64/libbinder.so (???) native: #06 pc 000000000001579c /system/lib64/libutils.so
(_ZN7android6Thread11_threadLoopEPv+208)
native: #07 pc 0000000000090598 /system/lib64/libandroid_runtime.so
(_ZN7android14AndroidRuntime15javaThreadShellEPv+96)
native: #08 pc 0000000000014fec /system/lib64/libutils.so (???)
native: #09 pc 0000000000067754 /system/lib64/libc.so (_ZL15__pthread_startPv+52) native: #10 pc 000000000001c644 /system/lib64/libc.so (__start_thread+16)
(no managed stack frames)
... //此处省略剩余的N个线程.
  1. trace参数解读
 "Binder_1" prio=5 tid=8 Native
| group="main" sCount=1 dsCount=0 obj=0x12c610a0 self=0x5573e5c750
| sysTid=12092 nice=0 cgrp=default sched=0/0 handle=0x7fa2743450
| state=S schedstat=( 796240075 863170759 3586 ) utm=50 stm=29 core=1 HZ=100 | stack=0x7fa2647000-0x7fa2649000 stackSize=1013KB
| held mutexes=

第0行:

  • 线程名: Binder_1(如有daemon则代表守护线程)
  • prio: 线程优先级
  • tid: 线程内部id
  • 线程状态: NATIVE
    第1行:
  • group: 线程所属的线程组
  • sCount: 线程挂起次数
  • dsCount: 用于调试的线程挂起次数 obj: 当前线程关联的java线程- - 对象 self: 当前线程地址
    第2行:
  • sysTid:线程真正意义上的tid nice: 调度有优先级
  • cgrp: 进程所属的进程调度组 sched: 调度策略
  • handle: 函数处理地址 第3行:
  • state: 线程状态
  • schedstat: CPU调度时间统计
  • utm/stm: 用户态/内核态的CPU时间(单位是jiffies) core: 该线程的最后运行所在核
  • HZ: 时钟频率
    第4行:
  • stack:线程栈的地址区间
  • stackSize:栈的大小 第5行:
  • mutex: 所持有mutex类型,有独占锁exclusive和共享锁shared两-

类 schedstat含义说明:

  • nice值越小则优先级越高。此处nice=-2, 可见优先级还是比较高的;

  • schedstat括号中的3个数字依次是Running、Runable、Switch,紧接着的是utm和stm

  • Running时间:CPU运行的时间,单位ns

  • Runable时间:RQ队列的等待时间,单位ns

  • Switch次数:CPU调度切换次数

  • utm: 该线程在用户态所执行的时间,单位是jiffies,jiffies定义为-
    sysconf(_SC_CLK_TCK),默认等 于10ms

  • stm: 该线程在内核态所执行的时间,单位是jiffies,默认等于10ms

可见,该线程Running=186667489018ns,也约等于186667ms。在CPU运行时间包括用户态(utm)和内核态 (stm)。 utm + stm = (12112 + 6554) ×10 ms = 186666ms。
结论:utm + stm = schedstat第一个参数值。

关键词: held 说明阻塞或者死锁,文件问题等

线上Anr监控

FileObserver: 监控某个目录/文件 状态发生改变 创建 删除文件
extends FileObserver : 监听 data/anr 目录是否发生变化,将trace.txt 文件上传 ,5.0之后不行。除非手机厂商修改selinux

WatchDog 方案,是个线程,检测死锁等
技巧:预防假唤醒

  long start = SystemClock.uptimeMillis();
                while (timeout > 0) {
                    if (Debug.isDebuggerConnected()) {
                        debuggerWasConnected = 2;
                    }
                    try {
                        wait(timeout);
                    } catch (InterruptedException e) {
                        Log.wtf(TAG, e);
                    }
                    if (Debug.isDebuggerConnected()) {
                        debuggerWasConnected = 2;
                    }
                    timeout = CHECK_INTERVAL - (SystemClock.uptimeMillis() - start);
                }

©著作权归作者所有,转载或内容合作请联系作者
禁止转载,如需转载请通过简信或评论联系作者。
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 216,372评论 6 498
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 92,368评论 3 392
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 162,415评论 0 353
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,157评论 1 292
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,171评论 6 388
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,125评论 1 297
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,028评论 3 417
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,887评论 0 274
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,310评论 1 310
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,533评论 2 332
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,690评论 1 348
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,411评论 5 343
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,004评论 3 325
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,659评论 0 22
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,812评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,693评论 2 368
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,577评论 2 353