前言
ANR 即 Application Not Responding,顾名思义就是应用程序无响应。在 Android 中,一般情况下,四大组件均是工作在主线程中的,Android 中的 Activity Manager 和 Window Manager 会随时监控应用程序的响应情况,如果因为一些耗时操作(网络请求或者 IO 操作)造成主线程阻塞一定时间(例如造成 5s 内不能响应用户事件或者 BroadcastReceiver 的 onReceive 方法执行时间超过 10s),那么系统就会显示 ANR 对话框提示用户对应的应用处于无响应状态。
虽然每个程序员都不想 ANR 发生在自己的头上,因此,你需要严格遵守 Google 提供的一系列建议(看这里),简单总结就是以下两点:
- 1. 不要让主线程干耗时的工作2. 不要让其他线程阻塞主线程的执行
因此,要尽量保证主线程执行工作干净利落,一个消息循环执行时间最好不超过 100ms 到 200ms,对于一些脏活累活可以交给 AsyncTask、HandlerThread、IntentService 或者另外起的新线程来完成,这样应用程序就能够及时响应用户的操作而不会给用户带来卡顿的感觉。
ANR 分析
一般应用程序在发布之前最好对新增的功能通过 Systrace+TraceView 进行性能测试,这样能够及时发现程序当中的耗时操作,对于一些可能引起 ANR 的风险做到提前规避。如果你是一个完美主义者,你也可以使用 StrictMode 来发现并干掉在你主线程中存在的一些磁盘 IO、网络操作或者 mysql"target="_blank"title="MySQL 知识库 "> 数据库读写等耗时代码,但是我个人觉得要完全避免在主线程进行这些操作还是不太现实,即使做到了也可能会造成应用程序的代码结构比较糟糕。
即使程序员在自己的环境中对代码进过了一系列的性能测试,到用户手中还是有中招的风险,毕竟再高效率的代码还是要时间来执行,而且不同手机性能差距还是很明显。如果你不幸中招,那么可以采用以下的方法来进行简单的分析。
导出 trace 文件
如果 ANR 发生,对应的应用会收到 SIGQUIT 异常终止信号,dalvik 虚拟机就会自动在 / data/anr / 目录下生成 trace.txt 文件,这个文件记录了在发生 ANR 时刻系统各个线程的执行状态,获取这个文件是不需要 root 权限的,因此首先需要做的就是通过 adb pull 命令将这个文件导出并等待分析。
trace 文件格式解析
导出 trace 文件后,可以看到类似于如下的文件内容:
- -----pid 901 at 2015 - 11 - 28 14 : 38 : 34-----Cmd line: system_serverJNI: CheckJNI is off;
- workarounds are off;
- pins = 6;
- globals = 2154(plus 409 weak) DALVIK THREADS: (mutexes: tll = 0 tsl = 0 tscl = 0 ghl = 0)"main"prio = 5 tid = 1 NATIVE | group = "main"sCount = 1 dsCount = 0 obj = 0x415a4e88 self = 0x414c48d8 | sysTid = 901 nice = -2 sched = 0 / 0 cgrp = apps handle = 1073926484 | state = S schedstat = (303590361913 618664734427 651535) utm = 19466 stm = 10893 core = 0#00 pc 00021914 / system / lib / libc.so(epoll_wait + 12)#01 pc 0001065f / system / lib / libutils.so(android: :Looper: :pollInner(int) + 98)#02 pc 00010889 / system / lib / libutils.so(android: :Looper: :pollOnce(int, int * , int * , void * *) + 92)#03 pc 0006b771 / system / lib / libandroid_runtime.so(android: :NativeMessageQueue: :pollOnce(_JNIEnv * , int) + 22)#04 pc 0002034c / system / lib / libdvm.so(dvmPlatformInvoke + 112)#05 pc 00050fcf / system / lib / libdvm.so(dvmCallJNIMethod(unsigned int const * , JValue * , Method const * , Thread * ) + 398)#06 pc 00000214 / dev / ashmem / dalvik - jit - code - cache(deleted) at android.os.MessageQueue.nativePollOnce(Native Method) at android.os.MessageQueue.next(MessageQueue.java: 138) at android.os.Looper.loop(Looper.java: 196) at com.android.server.ServerThread.initAndLoop(SystemServer.java: 1174) at com.android.server.SystemServer.main(SystemServer.java: 1271) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java: 515) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java: 878) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java: 694) at dalvik.system.NativeStart.main(Native Method)
首先需要了解这些参数表示的意义,我们挑其中关键的几个说明:
说明了发生 ANR 的进程 id、时间和进程名称。
- ----- pid 901 at 2015-11-28 14:38:34 -----Cmd line: system_server
其中 tll、tsl、tscl、ghl、hwl、hwll 分别对应:thread list lock, thread suspend lock, thread suspend count lock, gc heap lock, heap worker lock 和 heap worker list lock。
- JNI: CheckJNI is off;
- workarounds are off;
- pins = 6;
- globals = 2154(plus 409 weak) DALVIK THREADS: (mutexes: tll = 0 tsl = 0 tscl = 0 ghl = 0)
group 是线程组名称。sCount 是此线程被挂起的次数,dsCount 是线程被调试器挂起的次数,当一个进程被调试后,sCount 会重置为 0,调试完毕后 sCount 会根据是否被正常挂起增长,但是 dsCount 不会被重置为 0,所以 dsCount 也可以用来判断这个线程是否被调试过。obj 表示这个线程的 Java 对象的地址,self 表示这个线程本身的地址。
- | group="main" sCount=1 dsCount=0 obj=0x415a4e88 self=0x414c48d8
sysTid 是 Linux 下的内核线程 id,nice 是线程的调度优先级,sched 分别标志了线程的调度策略和优先级,cgrp 是调度属组,handle 是线程的处理函数地址。
- sysTid=901 nice=-2 sched=0/0 cgrp=apps handle=1073926484
state 是调度状态;schedstat 从 /proc/[pid]/task/[tid]/schedstat 读出,三个值分别表示线程在 cpu 上执行的时间、线程的等待时间和线程执行的时间片长度,有的 android 内核版本不支持这项信息,得到的三个值都是 0;utm 是线程用户态下使用的时间值 (单位是 jiffies);stm 是内核态下的调度时间值;core 是最后执行这个线程的 cpu 核的序号。
- state=S schedstat=( 303590361913 618664734427 651535 ) utm=19466 stm=10893 core=0
最后就是这个线程的调用栈信息。 通过分析 trace 文件得到 ANR 信息
通过上面分析,可以看到 trace 文件的头部就包含了很多与该线程相关的信息,但是并不是每个信息我们都必须弄懂,排查 ANR 的时候只需要找到其中关键的几个信息即可。一般可以通过以下几个简单的方法来判断。
trace 文件顶部的线程一般是 ANR 的元凶
这是一个简单的方法,但是大部分情况下都适用,可以通过这个方法来快速判断是否是自己的应用造成了本次 ANR。说明以下,并不是 trace 文件包含的应用就一定是造成 ANR 的帮凶,应用出现在 trace 文件中,只能说明出现 ANR 的时候这个应用进程还活着,trace 文件的顶部则是触发 ANR 的应用信息。因此,如果你的应用出现在了 trace 文件的顶部,那么很有可能是因为你的应用造成了 ANR,否则是你的应用造成 ANR 的可能性不大,但是具体是不是还需要进一步分析。例如:
- -----pid 1182 at 2015 - 11 - 26 01 : 53 : 34-----Cmd line: system_server JNI: CheckJNI is off;
- workarounds are off;
- pins = 5;
- globals = 2982(plus 135 weak) DALVIK THREADS: (mutexes: tll = 0 tsl = 0 tscl = 0 ghl = 0)"main"prio = 5 tid = 1 NATIVE | group = "main"sCount = 1 dsCount = 0 obj = 0x420a0e58 self = 0x4208f918 | sysTid = 1182 nice = -2 sched = 0 / 0 cgrp = apps handle = 1074594132 | state = S schedstat = (211672310629 149959255867 472114) utm = 13047 stm = 8120 core = 1#00 pc 000218b8 / system / lib / libc.so(epoll_wait + 12)...at android.os.MessageQueue.nativePollOnce(Native Method) at android.os.MessageQueue.next(MessageQueue.java: 138) at android.os.Looper.loop(Looper.java: 123) at com.android.server.ServerThread.initAndLoop(SystemServer.java: 1213) at com.android.server.SystemServer.main(SystemServer.java: 1317) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java: 515) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java: 793) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java: 609) at dalvik.system.NativeStart.main(Native Method)...-----end 1182----------pid 18927 at 2015 - 11 - 26 01 : 53 : 34-----Cmd line: com.android.example JNI: CheckJNI is off;
- workarounds are off;
- pins = 0;
- globals = 465(plus 984 weak) DALVIK THREADS: (mutexes: tll = 0 tsl = 0 tscl = 0 ghl = 0)"main"prio = 5 tid = 1 NATIVE | group = "main"sCount = 1 dsCount = 0 obj = 0x420a0e58 self = 0x4208f918 | sysTid = 18927 nice = -6 sched = 0 / 0 cgrp = apps handle = 1074594132 | state = S schedstat = (7748840431407 1615931922290 9994018) utm = 712375 stm = 62509 core = 1#00 pc 00020704 / system / lib / libc.so(__ioctl + 8)#01 pc 0002cfa3 / system / lib / libc.so(ioctl + 14)#02 pc 0001d3ed / system / lib / libbinder.so(android: :IPCThreadState: :talkWithDriver(bool) + 140)#03 pc 0001d8d7 / system / lib / libbinder.so(android: :IPCThreadState: :waitForResponse(android: :Parcel * , int * ) + 42)#04 pc 0001dadf / system / lib / libbinder.so(android: :IPCThreadState: :transact(int, unsigned int, android: :Parcel const & , android: :Parcel * , unsigned int) + 118)#05 pc 00019791 / system / lib / libbinder.so(android: :BpBinder: :transact(unsigned int, android: :Parcel const & , android: :Parcel * , unsigned int) + 30)...#23 pc 00000d80 / system / bin / app_process at android.os.BinderProxy.transact(Native Method) at android.app.IAlarmManager$Stub$Proxy.set(IAlarmManager.java: 154) at android.app.AlarmManager.setImpl(AlarmManager.java: 369) at android.app.AlarmManager.setRepeating(AlarmManager.java: 258) at android.os.Handler.handleCallback(Handler.java: 733) at android.os.Handler.dispatchMessage(Handler.java: 95) at android.os.Looper.loop(Looper.java: 136) at android.app.ActivityThread.main(ActivityThread.java: 5072) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java: 515) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java: 793) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java: 609) at dalvik.system.NativeStart.main(Native Method)
虽然应用 com.android.example 出现在了 trace 文件中,但是在 ANR 的时候它在通过 IPCThread 在进行进程间通信,而此次 ANR 发生于 system_server 获取用户事件的 native 方法里面,并不是我们的应用造成了 ANR。又例如下面的 trace 文件顶部内容为:
- -----pid 13406 at 2015 - 11 - 27 11 : 46 : 14-----Cmd line: com.android.example JNI: CheckJNI is off;
- workarounds are off;
- pins = 0;
- globals = 536(plus 102 weak) DALVIK THREADS: (mutexes: tll = 0 tsl = 0 tscl = 0 ghl = 0)"main"prio = 5 tid = 1 SUSPENDED | group = "main"sCount = 1 dsCount = 0 obj = 0x41795e58 self = 0x416b58b0 | sysTid = 13406 nice = -6 sched = 0 / 0 cgrp = apps handle = 1074557268 | state = S schedstat = (2352435524847 736727917292 2633566) utm = 213075 stm = 22168 core = 1 at java.lang.String. (String.java: ~261) at java.util.zip.ZipEntry. (ZipEntry.java: 392) at java.util.zip.ZipFile.readCentralDir(ZipFile.java: 414) at java.util.zip.ZipFile. (ZipFile.java: 151) at java.util.zip.ZipFile. (ZipFile.java: 123) at com.android.example.Utility.isValideFile(Utility.java: 2700) at com.android.example.Test.getPath(Test.java: 243) at com.android.example.Test$1.run(Test.java: 531) at android.os.Handler.handleCallback(Handler.java: 733) at android.os.Handler.dispatchMessage(Handler.java: 95) at android.os.Looper.loop(Looper.java: 136) at android.app.ActivityThread.main(ActivityThread.java: 5050) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java: 515) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java: 807) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java: 623) at dalvik.system.NativeStart.main(Native Method)...
这种情况说明 ANR 发生于 com.android.example 应用中,而且指明了 ANR 发生时代码的执行位置,这种情况十有八九就是我们应用程序的问题,之后就需要通过这个 trace 文件指明的路径来对代码进行排查。
注意死锁和等待
虽然说 ANR 一般情况是由于让主线程做了很多耗时的操作,但是死锁或者主线程等待也是 ANR 高发的原因,例如如下的 trace:
- -----pid 9436 at 2015 - 11 - 28 21 : 30 : 41-----Cmd line: com.example.yxz.myapplicationJNI: CheckJNI is off;
- workarounds are off;
- pins = 0;
- globals = 277DALVIK THREADS: (mutexes: tll = 0 tsl = 0 tscl = 0 ghl = 0)"main"prio = 5 tid = 1 MONITOR | group = "main"sCount = 1 dsCount = 0 obj = 0x415a4e88 self = 0x414c48d8 | sysTid = 9436 nice = 0 sched = 0 / 0 cgrp = apps handle = 1073926484 | state = S schedstat = (671264662 337280259 1005) utm = 53 stm = 14 core = 0 at com.example.yxz.myapplication.performancetest.WaitANR$InnerMonitorClass.TimeConsumeFunc(WaitANR.java: ~48) - waiting to lock < 0x447a5670 > held by tid = 11(Thread - 14208) at com.example.yxz.myapplication.performancetest.WaitANR$2.run(WaitANR.java: 32) at android.os.Handler.handleCallback(Handler.java: 733) at android.os.Handler.dispatchMessage(Handler.java: 95) at android.os.Looper.loop(Looper.java: 212) at android.app.ActivityThread.main(ActivityThread.java: 5135) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java: 515) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java: 878) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java: 694) at dalvik.system.NativeStart.main(Native Method)...."Thread-14208"prio = 10 tid = 11 TIMED_WAIT | group = "main"sCount = 1 dsCount = 0 obj = 0x447a4b98 self = 0x78296bb8 | sysTid = 9955 nice = -8 sched = 0 / 0 cgrp = apps handle = 2015978016 | state = S schedstat = (946045 640869 1) utm = 0 stm = 0 core = 2 at java.lang.VMThread.sleep(Native Method) at java.lang.Thread.sleep(Thread.java: 1013) at java.util.concurrent.TimeUnit.sleep(TimeUnit.java: 331) at com.example.yxz.myapplication.performancetest.WaitANR$InnerMonitorClass.TimeConsumeFunc(WaitANR.java: 48) at com.example.yxz.myapplication.performancetest.WaitANR$1.run(WaitANR.java: 20) at java.lang.Thread.run(Thread.java: 841)
从 trace 文件可以看出,发生 ANR 的主线程正处于 monitor 状态,也就是它在等待一个 synchronized 块或者方法,但是目前这个 monitor 正在被 tid=11 的线程持有,所以造成了主线程被阻塞,从而发生了 ANR。死锁的分析也是类似,发生死锁的线程一般处于 MONITOR 状态或者 WAIT 状态,等待其他进程的锁或者 monitor,而其他进程又在等待另外线程的锁或者 monitor,一直这样依赖下去,直到形成一个环。
结束
以上都是自己总结,欢迎提出意见和拍砖!
就爱阅读 www.92to.com 网友整理上传, 为您提供最全的知识大全, 期待您的分享,转载请注明出处。
来源: