Android(安卓)ANR 分析学习总结（转）
16lz
2021-01-25
1. 什么情况下会发生anr
(1). KeyDispatchTimeout(5 seconds) --主要类型按键或触摸事件在特定时间内无响应
(2). BroadcastTimeout(10 seconds) --BroadcastReceiver在特定时间内无法处理完成
(3). ServiceTimeout(20 seconds) --小概率类型 Service在特定的时间内无法处理完成
2. KeyDispatchTimeout超时原因
(1). 当前的事件没有机会得到处理（即UI线程正在处理前一个事件，没有及时的完成或者looper被某种原因阻塞住了）
(2). 当前的事件正在处理，但没有及时完成
首先要知道事件发生的线程，一般来说大多数可能是ui线程操作超时，那么ui线程都有哪些呢：
(1). Activity 生命周期
(2). View post 的runnable方法 、 handler（MainLooper） 的 handleMessage()
(3). Asycktask 的 onPreExecute(), onPostExecute() , onProgressUpdate()方法
(4). Broadcast 的onReceive()
(5). Service
其他原因造成的anr：
(1). 线程死锁
(2). cpu 饥饿
3. 举例
(1) 普通的，可以直接查看trace.txt （http://www.eoeandroid.com/thread-152008-1-1.html?_dsign=554288df）
获取trace.txt 文件 adb shell cat /data/anr/traces.txt > d:/traces.txt （拷贝到d盘）
----- pid 2328 at 2011-12-21 09:36:36 -----Cmd line: system_serverDALVIK THREADS:(mutexes: tll=0 tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)"main" prio=5 tid=1 SUSPENDED | group="main" sCount=1 dsCount=0 obj=0x4001f180 self=0xce48 | sysTid=2328 nice=0 sched=0/0 cgrp=default handle=-1345006248 | schedstat=( 2251911039 10737773873 799 ) at java.util.ArrayList.size(ArrayList.java:~322) 这里就是案发现场 at java.util.Collections.sort(Collections.java:1964) at com.android.server.IntentResolver.sortResults(IntentResolver.java:334) at com.android.server.IntentResolver.queryIntent(IntentResolver.java:305) at com.android.server.am.ActivityManagerService.broadcastIntentLocked(ActivityManagerService.java:10288) at com.android.server.am.ActivityManagerService.broadcastIntent(ActivityManagerService.java:10478) at android.app.ContextImpl.sendStickyBroadcast(ContextImpl.java:736) at com.android.server.TelephonyRegistry.broadcastServiceStateChanged(TelephonyRegistry.java:500) at com.android.server.TelephonyRegistry.notifyServiceState(TelephonyRegistry.java:267) at com.android.internal.telephony.ITelephonyRegistry$Stub.onTransact(ITelephonyRegistry.java:81) at android.os.Binder.execTransact(Binder.java:320) at com.android.server.SystemServer.init1(Native Method) at com.android.server.SystemServer.main(SystemServer.java:854) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java:507) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:839) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:597) at dalvik.system.NativeStart.main(Native Method)"Binder Thread #6" prio=5 tid=46 NATIVE | group="main" sCount=1 dsCount=0 obj=0x406fd210 self=0x44b398 | sysTid=2592 nice=0 sched=0/0 cgrp=default handle=4321440 | schedstat=( 131676112 959825670 94 ) at dalvik.system.NativeStart.run(Native Method)"Thread-57" prio=5 tid=47 NATIVE | group="main" sCount=1 dsCount=0 obj=0x406f3068 self=0xd7f80 | sysTid=2561 nice=10 sched=0/0 cgrp=bg_non_interactive handle=3488688 | schedstat=( 89258622 34068288100 28 ) at android.content.res.AssetManager.getStringBlockCount(Native Method) at android.content.res.AssetManager.makeStringBlocks(AssetManager.java:256) at android.content.res.AssetManager.ensureStringBlocks(AssetManager.java:248) at android.content.res.Resources.(Resources.java:160) at android.app.ActivityThread.getTopLevelResources(ActivityThread.java:1202) at android.app.ActivityThread.getTopLevelResources(ActivityThread.java:1229) at android.app.ContextImpl$ApplicationPackageManager.getResourcesForApplication(ContextImpl.java:2372) at android.app.ContextImpl$ApplicationPackageManager.getXml(ContextImpl.java:2597) at android.content.pm.PackageItemInfo.loadXmlMetaData(PackageItemInfo.java:216) at android.app.SearchableInfo.getActivityMetaData(SearchableInfo.java:515) at android.server.search.Searchables.buildSearchableList(Searchables.java:215) at android.server.search.SearchManagerService.getSearchables(SearchManagerService.java:66) at android.server.search.SearchManagerService.access$200(SearchManagerService.java:38) at android.server.search.SearchManagerService$BootCompletedReceiver$1.run(SearchManagerService.java:82) (2) 通过Android trace文件分析死锁ANR
ps 另外的例子http://www.eoeandroid.com/thread-94087-1-1.html?_dsign=94256d94
DALVIK THREADS:"main" prio=5 tid=1 TIMED_WAIT| group="main" sCount=1 dsCount=0 s=N obj=0x400208b8 self=0xcdf0| sysTid=1732 nice=0 sched=0/0 cgrp=unknown handle=-1345026000at java.lang.Object.wait(Native Method)- waiting on <0x4a5ba4b0> (a com.gameloft.robin.DeadLockTraceActivity) forceWait等待 <0x4a5ba4b0> at java.lang.Object.wait(Object.java:326) at com.gameloft.robin.DeadLockTraceActivity.forceWait(DeadLockTraceActivity.java:24)at com.gameloft.robin.DeadLockTraceActivity$1.run(DeadLockTraceActivity.java:18) 匿名内部类1中at android.os.Handler.handleCallback(Handler.java:587)at android.os.Handler.dispatchMessage(Handler.java:92)at android.os.Looper.loop(Looper.java:123)at android.app.ActivityThread.main(ActivityThread.java:4633)at java.lang.reflect.Method.invokeNative(Native Method)at java.lang.reflect.Method.invoke(Method.java:521)at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)at dalvik.system.NativeStart.main(Native Method)这里列举下，线程的几种状态
ThreadState (defined at “dalvik/vm/thread.h “)
THREAD_UNDEFINED = -1, /* makes enum compatible with int32_t /
THREAD_ZOMBIE = 0, / TERMINATED /
THREAD_RUNNING = 1, / RUNNABLE or running now /
THREAD_TIMED_WAIT = 2, / TIMED_WAITING in Object.wait() /
THREAD_MONITOR = 3, / BLOCKED on a monitor /
THREAD_WAIT = 4, / WAITING in Object.wait() /
THREAD_INITIALIZING= 5, / allocated, not yet running /
THREAD_STARTING = 6, / started, not yet on thread list /
THREAD_NATIVE = 7, / off in a JNI native method /
THREAD_VMWAIT = 8, / waiting on a VM resource /
THREAD_SUSPENDED = 9, / suspended, usually by GC or debugger */
上述处于TIMED_WAIT 。
http://fanli7.net/a/bianchengyuyan/C__/20130616/371042.html
"PowerManagerService" prio=5 tid=24 MONITOR 在tid为24中 | group="main" sCount=1 dsCount=0 obj=0x41dd0eb0 self=0x5241b218 | sysTid=567 nice=0 sched=0/0 cgrp=apps handle=1380038664 | state=S schedstat=( 6682116007 11324451214 33313 ) utm=450 stm=219 core=1 at com.android.server.am.ActivityManagerService.broadcastIntent(ActivityManagerService.java:~13045) - waiting to lock <0x41a874a0> (a com.android.server.am.ActivityManagerService) held by tid=12 (android.server.ServerThread) tid 为12的家伙持有了0x41a874a0资源 at android.app.ContextImpl.sendBroadcast(ContextImpl.java:1144) at com.android.server.power.PowerManagerService$DisplayBlankerImpl.unblankAllDisplays(PowerManagerService.java:3442) at com.android.server.power.DisplayPowerState$PhotonicModulator$1.run(DisplayPowerState.java:456) at android.os.Handler.handleCallback(Handler.java:800) at android.os.Handler.dispatchMessage(Handler.java:100) at android.os.Looper.loop(Looper.java:194) at android.os.HandlerThread.run(HandlerThread.java:60) "Binder_B" prio=5 tid=85 MONITOR 在tid 为85中 | group="main" sCount=1 dsCount=0 obj=0x42744770 self=0x58329e88 | sysTid=3700 nice=-20 sched=0/0 cgrp=apps handle=1471424616 | state=S schedstat=( 1663727513 2044643318 6806 ) utm=132 stm=34 core=1 at com.android.server.power.PowerManagerService$DisplayBlankerImpl.toString(PowerManagerService.java:~3449) - waiting to lock <0x41a7e420> (a com.android.server.power.PowerManagerService$DisplayBlankerImpl) held by tid=24 (PowerManagerService) tid 为24的家伙持有了0x41a7e420资源 at java.lang.StringBuilder.append(StringBuilder.java:202) at com.android.server.power.PowerManagerService.dump(PowerManagerService.java:3052) at android.os.Binder.dump(Binder.java:264) at android.os.Binder.onTransact(Binder.java:236) at android.os.IPowerManager$Stub.onTransact(IPowerManager.java:373) at android.os.Binder.execTransact(Binder.java:351) at dalvik.system.NativeStart.run(Native Method) "android.server.ServerThread" prio=5 tid=12 MONITOR 在tid为12的线程中 | group="main" sCount=1 dsCount=0 obj=0x41a76178 self=0x507837a8 | sysTid=545 nice=-2 sched=0/0 cgrp=apps handle=1349936616 | state=S schedstat=( 15368096286 21707846934 69485 ) utm=1226 stm=310 core=0 at com.android.server.power.PowerManagerService.isScreenOnInternal(PowerManagerService.java:~2529) - waiting to lock <0x41a7e2e8> (a java.lang.Object) held by tid=85 (Binder_B) tid 为85的家伙持有了0x41a7e2e8资源 at com.android.server.power.PowerManagerService.isScreenOn(PowerManagerService.java:2522) at com.android.server.wm.WindowManagerService.sendScreenStatusToClientsLocked(WindowManagerService.java:7749) at com.android.server.wm.WindowManagerService.setEventDispatching(WindowManagerService.java:7628) at com.android.server.am.ActivityManagerService.updateEventDispatchingLocked(ActivityManagerService.java:8083) at com.android.server.am.ActivityManagerService.wakingUp(ActivityManagerService.java:8077) at com.android.server.power.Notifier.sendWakeUpBroadcast(Notifier.java:474) at com.android.server.power.Notifier.sendNextBroadcast(Notifier.java:455) at com.android.server.power.Notifier.access$700(Notifier.java:62) at com.android.server.power.Notifier$NotifierHandler.handleMessage(Notifier.java:600) at android.os.Handler.dispatchMessage(Handler.java:107) at android.os.Looper.loop(Looper.java:194) at com.android.server.ServerThread.run(SystemServer.java:1328)即
tid=24 等待tid =12 的资源0x41a874a0
tid = 85 等待tid= 24的资源0x41a874a0
tid =12 等待tid =85 的资源0x41a7e2e8
这样就形成了一个死锁。
(3) cpu 饥饿 （Android ANR 分析解决方法）
先看log
4-01 13:12:11.572 I/InputDispatcher( 220): Application is not responding:Window{2b263310com.android.email/com.android.email.activity.SplitScreenActivitypaused=false}. 5009.8ms since event, 5009.5ms since waitstarted 04-0113:12:11.572 I/WindowManager( 220): Input event dispatching timedout sending tocom.android.email/com.android.email.activity.SplitScreenActivity 04-01 13:12:14.123 I/Process( 220): Sending signal. PID: 21404 SIG: 3---发生ANR的时间和生成trace.txt的时间 04-01 13:12:14.123 I/dalvikvm(21404):threadid=4: reacting to signal 3 …… 04-0113:12:15.872 E/ActivityManager( 220): ANR in com.android.email(com.android.email/.activity.SplitScreenActivity) 04-0113:12:15.872 E/ActivityManager( 220): Reason:keyDispatchingTimedOut 04-0113:12:15.872 E/ActivityManager( 220): Load: 8.68 / 8.37 / 8.53 04-0113:12:15.872 E/ActivityManager( 220): CPUusage from 4361ms to 699ms ago ----CPU在ANR发生前的使用情况 04-0113:12:15.872 E/ActivityManager( 220): 5.5%21404/com.android.email: 1.3% user + 4.1% kernel / faults: 10 minor 04-0113:12:15.872 E/ActivityManager( 220): 4.3%220/system_server: 2.7% user + 1.5% kernel / faults: 11 minor 2 major 04-0113:12:15.872 E/ActivityManager( 220): 0.9%52/spi_qsd.0: 0% user + 0.9% kernel 04-0113:12:15.872 E/ActivityManager( 220): 0.5%65/irq/170-cyttsp-: 0% user + 0.5% kernel 04-0113:12:15.872 E/ActivityManager( 220): 0.5%296/com.android.systemui: 0.5% user + 0% kernel 04-0113:12:15.872 E/ActivityManager( 220): 100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait 04-0113:12:15.872 E/ActivityManager( 220): CPUusage from 3697ms to 4223ms later:-- ANR后CPU的使用量 04-0113:12:15.872 E/ActivityManager( 220): 25%21404/com.android.email: 25% user + 0% kernel / faults: 191 minor 04-0113:12:15.872 E/ActivityManager( 220): 16% 21603/__eas(par.hakan: 16% user + 0% kernel 04-0113:12:15.872 E/ActivityManager( 220): 7.2% 21406/GC: 7.2% user + 0% kernel 04-0113:12:15.872 E/ActivityManager( 220): 1.8% 21409/Compiler: 1.8% user + 0% kernel 04-0113:12:15.872 E/ActivityManager( 220): 5.5%220/system_server: 0% user + 5.5% kernel / faults: 1 minor 04-0113:12:15.872 E/ActivityManager( 220): 5.5% 263/InputDispatcher: 0% user + 5.5% kernel 04-0113:12:15.872 E/ActivityManager( 220): 32%TOTAL: 28% user + 3.7% kernel注意，中间注释。
04-0113:12:15.872 E/ActivityManager( 220): 100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait cpu使用率100%
其次，定位在traceview.txt。
-----pid 21404 at 2011-04-01 13:12:14 ----- Cmdline: com.android.email DALVIK THREADS: (mutexes: tll=0tsl=0 tscl=0 ghl=0 hwl=0 hwll=0) "main" prio=5 tid=1NATIVE | group="main" sCount=1 dsCount=0obj=0x2aad2248 self=0xcf70 | sysTid=21404 nice=0 sched=0/0cgrp=[fopen-error:2] handle=1876218976 atandroid.os.MessageQueue.nativePollOnce(Native Method) atandroid.os.MessageQueue.next(MessageQueue.java:119) atandroid.os.Looper.loop(Looper.java:110) at android.app.ActivityThread.main(ActivityThread.java:3688) at java.lang.reflect.Method.invokeNative(Native Method) atjava.lang.reflect.Method.invoke(Method.java:507) atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:624) at dalvik.system.NativeStart.main(Native Method)
更多相关文章
- 不吹不黑！GitHub 上帮助人们学习编码的 12 个资源，错过血亏...
- 一款霸榜 GitHub 的开源 Linux 资源监视器！
- OkHttp源码解析
- android动画之通过子线程来实现动画
- Android(安卓)资料整理
- android addIdleHandler 空闲线程 解析
- Android(安卓)资源和国际化
- Android(安卓)API学习 SoundPool 和 MediaPlayer
- android anr traces日志分析方法