Android 系統穩定性之ANR

阿新 • • 發佈：2019-01-05

相信大部分Android 開發人員都遇到過ANR問題，本文根據一些實際的開發經歷介紹一下如何解決和避免ANR問題。

一，何為ANR

ANR是“Application Not Responding”的縮寫，即“應用程式無響應”。在Android中，ActivityManagerService（簡稱AMS）和WindowManagerService

（簡稱WMS）會監測應用程式的響應時間，如果應用程式主執行緒（即UI執行緒）在超時時間內對輸入事件沒有處理完畢，或者對特定操作沒有執行完畢，就會出現ANR。對於輸入事件沒有處理完畢產生的ANR，Android會顯示一個對話方塊，提示使用者當前應用程式沒有響應，使用者可以選擇繼續等待或者關閉這個應用程式（也就是殺掉這個應用程式的程序）。

產生ANR的原因：

主執行緒對輸入事件在5秒內沒有處理完畢
主執行緒在執行BroadcastReceiver的onReceive函式時10秒內沒有執行完畢
主執行緒在執行Service的各個生命週期函式時20秒內沒有執行完畢

由於廣播接收器和Service都是無介面的，在上述三種ANR事件中只有1有介面提示，其他兩種只輸出日誌。三種ANR均會輸出log日誌，同時還會將各個應用程式程序的函式堆疊輸出到/data/data/anr/trace.txt中，這個檔案是分析ANR原因的關鍵檔案。

二，如何分析ANR

在Android測試工具Monkey博文中介紹了通過Monkey工具可以發現一些潛在的ANR風險，這裡將介紹一旦出現ANR異常如何來分析。log和trace.txt就是兩個利器。老規矩，還是先貼個例子上來分析。

log 資訊分析：

:Sending Flip keyboardOpen=true
:Sending Touch (ACTION_DOWN): 0:(24.0,570.0)
    //[calendar_time:2014-08-16 12:44:38.403  system_uptime:263794]
    // Sending event #3300
:Sending Touch (ACTION_UP): 0:(51.368206,570.24054)
:Switch: #Intent;action=android.intent.action.MAIN;category=android.intent.category.LAUNCHER;launchFlags=0x10200000;component=com.hybroad.launcher/.activity.PreLauncherActivity;end
    // Allowing start of Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] cmp=com.hybroad.launcher/.activity.PreLauncherActivity } in package com.hybroad.launcher
:Sending Touch (ACTION_DOWN): 0:(1101.0,1020.0)
:Sending Touch (ACTION_UP): 0:(1165.5239,1050.6898)
[  183.601062] RTL871X: survey done event(2)
    // Rejecting start of Intent { act=android.intent.action.MAIN cat=[android.intent.category.HOME] cmp=android/com.android.internal.app.ResolverActivity } in package android
:Sending Touch (ACTION_DOWN): 0:(1672.0,963.0)
:Sending Touch (ACTION_UP): 0:(1607.745,971.0462)
 // NOT RESPONDING: com.hybroad.launcher (pid 6012)
 // com.hybroad.lanucher 出現了ANR，由SubMenuActivity裡的操作導致的
 ANR in com.hybroad.launcher (com.hybroad.launcher/.activity.SubMenuActivity)
// ANR 原因是keyDispatching 超時，UI執行緒超5秒未響應
 Reason: keyDispatchingTimedOut
Load: 3.97 / 2.2 / 0.93
// 下面是CPU使用率，system_server 佔用CPU過多，ago表示發生ANR之前的CPU使用情況。
//later 是ANR之後CPU使用情況
 CPU usage from 6313ms to 101ms ago:
  98% 1375/system_server: 52% user + 45% kernel / faults: 2239 minor
  75% 1630/com.hybroad.phone_remote: 39% user + 35% kernel / faults: 131 minor
  68% 2385/com.hybroad.airplay: 40% user + 28% kernel / faults: 17 minor
  18% 1035/tvos: 9.3% user + 9.1% kernel
  18% 6012/com.hybroad.launcher: 13% user + 5.3% kernel / faults: 3363 minor 5 major
  5.6% 1019/surfaceflinger: 2% user + 3.5% kernel
  2.5% 5657/mediaserver: 0.3% user + 2.2% kernel / faults: 18 minor
  0.6% 1608/com.hybroad.inputmethod.remote: 0.6% user + 0% kernel / faults: 1 minor
  0.6% 4772/com.android.commands.monkey: 0.3% user + 0.3% kernel / faults: 24 minor
  0.3% 1029/livecap: 0% user + 0.3% kernel
  0.3% 2255/RTW_CMD_THREAD: 0% user + 0.3% kernel
  0.1% 5/kworker/u:0: 0% user + 0.1% kernel
  0.1% 22/kworker/u:1: 0% user + 0.1% kernel
  0.1% 420/cifs_mem_clear: 0.1% user + 0% kernel
  0.1% 1812/mdnsd: 0% user + 0.1% kernel / faults: 1 minor
  0% 2244/rel_supplicant: 0% user + 0% kernel / faults: 51 minor 3 major
49% TOTAL: 27% user + 21% kernel + 0% softirq
CPU usage from 681ms to 1214ms later:
  67% 1375/system_server: 37% user + 30% kernel / faults: 23 minor
    7.5% 1728/Binder_7: 5.6% user + 1.8% kernel
    5.6% 1688/Binder_3: 3.7% user + 1.8% kernel
    5.6% 1689/Binder_4: 1.8% user + 3.7% kernel
    5.6% 1729/Binder_8: 3.7% user + 1.8% kernel
    5.6% 1899/Binder_A: 3.7% user + 1.8% kernel
    3.7% 1375/system_server: 1.8% user + 1.8% kernel
    3.7% 1386/Binder_1: 3.7% user + 0% kernel
    3.7% 1387/Binder_2: 1.8% user + 1.8% kernel
    3.7% 1397/ActivityManager: 0% user + 3.7% kernel
    3.7% 1714/Binder_5: 1.8% user + 1.8% kernel
    3.7% 1715/Binder_6: 3.7% user + 0% kernel
    3.7% 1730/Binder_9: 1.8% user + 1.8% kernel
    3.7% 1900/Binder_B: 3.7% user + 0% kernel
  33% 1630/com.hybroad.phone_remote: 24% user + 9.4% kernel / faults: 1 minor
    30% 1813/Timer-0: 22% user + 7.5% kernel
  16% 1035/tvos: 3.7% user + 13% kernel
    3.7% 1369/1035keypad Inpu: 1.8% user + 1.8% kernel
    3.7% 1414/HDMITx_Task: 3.7% user + 0% kernel
    3.7% 1700/Mdebug Monitor: 0% user + 3.7% kernel
    1.8% 1406/Picture Monitor: 0% user + 1.8% kernel
    1.8% 1698/Internal_MHLthr: 0% user + 1.8% kernel
  3.7% 1019/surfaceflinger: 0% user + 3.7% kernel
    3.7% 1186/SurfaceFlinger: 0% user + 3.7% kernel
  3.7% 2385/com.hybroad.airplay: 3.7% user + 0% kernel
    3.7% 2402/Timer-0: 3.7% user + 0% kernel
33% TOTAL: 17% user + 15% kernel

procrank:
  PID      Vss      Rss      Pss      Uss  cmdline
 1375   70196K   69848K   47811K   44824K  system_server
 1515   66980K   64488K   43472K   40784K  com.android.systemui
 6012   55568K   43604K   23783K   21476K  com.hybroad.launcher
 1035   56792K   18508K   17888K   17580K  /applications/bin/tvos
 1630   31496K   31412K   13415K   12060K  com.hybroad.phone_remote
 1020   37196K   37072K   10593K    5184K  zygote
 5511   39404K   28252K    9760K    7964K  com.android.systemui:screenshot
 4772   22584K   22556K    9660K    6436K  com.android.commands.monkey
 1954   24868K   24780K    6770K    5188K  com.miui.mihome2
 1921   23480K   23388K    6647K    5312K  com.miui.mihome.lockscreen
 5657   10796K   10792K    6327K    5164K  /system/bin/mediaserver
 1532   22468K   22380K    5764K    4708K  android.process.media
 1660   24420K   24344K    5759K    4224K  system:ui
 1560   23100K   23004K    5574K    4172K  com.miui.mihome2:download
 1641   21048K   20948K    4481K    3524K  com.jrm.servicecontainer
 1608   20764K   20680K    4463K    3532K  com.hybroad.inputmethod.remote
 2385   18860K   18764K    3807K    3048K  com.hybroad.airplay
 1019   46628K    7604K    3380K    2328K  /system/bin/surfaceflinger
 1778   18440K   18348K    3262K    2504K  com.hybroad.dlna
 1574   18404K   18296K    3024K    2200K  com.mstar.android.providers.tv
 1794   17868K   17772K    2728K    1812K  com.hybroad.phone_remote.daemon
 1820   17444K   17344K    2621K    1868K  org.opencv.engine:OpenCVEngineProcess
 1652   17396K   17296K    2531K    1772K  com.broadcom.bluetoothmonitor
 1871   16808K   16712K    2434K    1708K  com.android.settings
 2035   16416K   16312K    2223K    1500K  com.jrm.localmm
 1018    2440K    2440K    2101K    2088K  /system/bin/debuggerd
 1905   16432K   16332K    2095K    1388K  com.android.onetimeinitializer
 2426   16104K   16004K    2064K    1356K  com.mstar.tvsetting
 1029    5072K    5072K    1818K    1260K  /system/bin/livecap
 1021    4372K    4372K    1490K    1024K  /system/bin/drmserver
 6274    1652K    1652K    1410K    1404K  procrank
 1028    1252K    1252K     975K     968K  /system/bin/upnp_tv_receiver
 2244    1892K    1892K     955K     832K  rel_supplicant
 1027   22020K    2180K     788K     316K  /system/bin/virtualkeypad
 1017    1612K    1612K     744K     644K  /system/bin/netd
 1015    1508K    1508K     679K     596K  /system/bin/vold
 1812     848K     848K     553K     544K  /system/bin/mdnsd
    1     536K     536K     450K     388K  /init
 1024    1228K    1228K     435K     360K  /system/bin/keystore
 2242     356K     356K     356K     356K  /system/bin/busybox
 1016     928K     928K     355K     316K  /system/bin/resourcemanager
 1031     716K     716K     226K     208K  /system/bin/browserserver
 2905     488K     488K     205K     128K  sh
 1036     476K     476K     197K     120K  /system/bin/sh
 2091     504K     504K     187K     176K  /system/bin/dhcpcd
 1023     456K     456K     162K     152K  /system/bin/installd
  674     220K     220K     154K      92K  /sbin/ueventd
 1037     168K     168K     148K     148K  /sbin/adbd
 6216     432K     428K     147K     132K  /system/bin/dnssd
 1014     348K     344K     109K     104K  /system/bin/servicemanager
 1026     348K     344K     105K     100K  /system/bin/logwrapper
 1034     332K     332K      94K      88K  /system/bin/dnssd_daemon
                          ------   ------  ------
                         267207K  226160K  TOTAL

再看trace檔案，只載錄部分：

----- pid 6012 at 2014-08-16 12:44:43 -----
Cmd line: com.hybroad.launcher
//開頭顯示程序號、ANR發生的時間點和程序名稱
JNI: CheckJNI is off; workarounds are off; pins=0; globals=159

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
//依次是：執行緒名、執行緒優先順序、執行緒建立時的序號執行緒當前狀態
 "main" prio=5 tid=1 SUSPENDED
// 執行緒名：main 優先順序5  建立序號 1 執行緒狀態：SUSPENDED
  | sysTid=6012 nice=0 sched=0/0 cgrp=apps handle=1074671612
  | state=S schedstat=( 2402929933 1242053208 8116 ) utm=191 stm=48 core=1
  at android.view.ViewRootImpl.performTraversals(ViewRootImpl.java:~1585)
  at android.view.ViewRootImpl.doTraversal(ViewRootImpl.java:1045)
  at android.view.ViewRootImpl$TraversalRunnable.run(ViewRootImpl.java:5522)
  at android.view.Choreographer$CallbackRecord.run(Choreographer.java:749)
  at android.view.Choreographer.doCallbacks(Choreographer.java:562)
  at android.view.Choreographer.doFrame(Choreographer.java:532)
  at android.view.Choreographer$FrameDisplayEventReceiver.run(Choreographer.java:735)
  at android.os.Handler.handleCallback(Handler.java:730)
  at android.os.Handler.dispatchMessage(Handler.java:92)
  at android.os.Looper.loop(Looper.java:137)
  at android.app.ActivityThread.main(ActivityThread.java:5103)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:525)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:773)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:589)
  at dalvik.system.NativeStart.main(Native Method)

"PriorityExecutor #5" prio=5 tid=15 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4214d3d8 self=0x52301318
  | sysTid=6041 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1378883432
  | state=S schedstat=( 341597 4190770 3 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4214d550> (a java.lang.VMThread) held by tid=15 (PriorityExecutor #5)
  at java.lang.Thread.parkFor(Thread.java:1205)
  at sun.misc.Unsafe.park(Unsafe.java:325)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at com.lidroid.xutils.task.PriorityObjectBlockingQueue.take(PriorityObjectBlockingQueue.java:274)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:841)

"PriorityExecutor #4" prio=5 tid=14 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4214c958 self=0x5272d980
  | sysTid=6040 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1383259600
  | state=S schedstat=( 16335142 37377692 95 ) utm=1 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4214ca98> (a java.lang.VMThread) held by tid=14 (PriorityExecutor #4)
  at java.lang.Thread.parkFor(Thread.java:1205)
  at sun.misc.Unsafe.park(Unsafe.java:325)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at com.lidroid.xutils.task.PriorityObjectBlockingQueue.take(PriorityObjectBlockingQueue.java:274)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:841)

"PriorityExecutor #3" prio=5 tid=13 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4214be90 self=0x5272e6a8
  | sysTid=6039 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1383257392
  | state=S schedstat=( 1407948 916560 16 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4214c140> (a java.lang.VMThread) held by tid=13 (PriorityExecutor #3)
  at java.lang.Thread.parkFor(Thread.java:1205)
  at sun.misc.Unsafe.park(Unsafe.java:325)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at com.lidroid.xutils.task.PriorityObjectBlockingQueue.take(PriorityObjectBlockingQueue.java:274)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:841)

"PriorityExecutor #2" prio=5 tid=12 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x42154638 self=0x5272cc90
  | sysTid=6038 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1383256288
  | state=S schedstat=( 20251581 51870492 151 ) utm=1 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x421547d0> (a java.lang.VMThread) held by tid=12 (PriorityExecutor #2)
  at java.lang.Thread.parkFor(Thread.java:1205)
  at sun.misc.Unsafe.park(Unsafe.java:325)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at com.lidroid.xutils.task.PriorityObjectBlockingQueue.take(PriorityObjectBlockingQueue.java:274)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:841)

"PriorityExecutor #1" prio=5 tid=11 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x42154370 self=0x52730630
  | sysTid=6037 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1103892024
  | state=S schedstat=( 2237642 16217040 18 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x42154530> (a java.lang.VMThread) held by tid=11 (PriorityExecutor #1)
  at java.lang.Thread.parkFor(Thread.java:1205)
  at sun.misc.Unsafe.park(Unsafe.java:325)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at com.lidroid.xutils.task.PriorityObjectBlockingQueue.take(PriorityObjectBlockingQueue.java:274)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:841)

"Binder_2" prio=5 tid=10 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x421416c0 self=0x41c1e638
  | sysTid=6024 nice=0 sched=0/0 cgrp=apps handle=1103225840
  | state=S schedstat=( 2307968 2046145 22 ) utm=0 stm=0 core=0
  #00  pc 0001b320  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002b9ab  /system/lib/libc.so (ioctl+14)
  #02  pc 0001b539  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
  #03  pc 0001bcd7  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001fae9  /system/lib/libbinder.so
  #05  pc 00011a8d  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
  #06  pc 0004bd21  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
  #07  pc 00011581  /system/lib/libutils.so
  #08  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

"Binder_1" prio=5 tid=9 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x421409b8 self=0x41c1db88
  | sysTid=6023 nice=0 sched=0/0 cgrp=apps handle=1103223104
  | state=S schedstat=( 3963651 6845165 24 ) utm=0 stm=0 core=2
  #00  pc 0001b320  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002b9ab  /system/lib/libc.so (ioctl+14)
  #02  pc 0001b539  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
  #03  pc 0001bcd7  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001fae9  /system/lib/libbinder.so
  #05  pc 00011a8d  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
  #06  pc 0004bd21  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
  #07  pc 00011581  /system/lib/libutils.so
  #08  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

"FinalizerWatchdogDaemon" daemon prio=5 tid=8 WAIT
  | group="system" sCount=1 dsCount=0 obj=0x4213d7e8 self=0x41c1d0a0
  | sysTid=6022 nice=0 sched=0/0 cgrp=apps handle=1103222000
  | state=S schedstat=( 169252 273121 4 ) utm=0 stm=0 core=2
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41ea2830> (a java.lang.Daemons$FinalizerWatchdogDaemon)
  at java.lang.Object.wait(Object.java:364)
  at java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230)
  at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207)
  at java.lang.Thread.run(Thread.java:841)

"FinalizerDaemon" daemon prio=5 tid=7 WAIT
  | group="system" sCount=1 dsCount=0 obj=0x4213d638 self=0x59cd1148
  | sysTid=6021 nice=0 sched=0/0 cgrp=apps handle=1506612632
  | state=S schedstat=( 19178147 5530289 45 ) utm=1 stm=0 core=3
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41e8b568> (a java.lang.ref.ReferenceQueue)
  at java.lang.Object.wait(Object.java:401)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
  at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170)
  at java.lang.Thread.run(Thread.java:841)

"ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
  | group="system" sCount=1 dsCount=0 obj=0x4213d4d0 self=0x59cd08a8
  | sysTid=6020 nice=0 sched=0/0 cgrp=apps handle=1506610424
  | state=S schedstat=( 2228290 3801987 33 ) utm=0 stm=0 core=2
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41e8b490> 
  at java.lang.Object.wait(Object.java:364)
  at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130)
  at java.lang.Thread.run(Thread.java:841)

"Compiler" daemon prio=5 tid=5 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x4213d3e0 self=0x59cd0250
  | sysTid=6019 nice=0 sched=0/0 cgrp=apps handle=1506607112
  | state=S schedstat=( 365619316 81085896 3099 ) utm=17 stm=18 core=1
  #00  pc 0001c5f0  /system/lib/libc.so (__futex_syscall3+8)
  #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
  #02  pc 0000e708  /system/lib/libc.so (__pthread_cond_timedwait+64)
  #03  pc 0007307b  /system/lib/libdvm.so
  #04  pc 0005440d  /system/lib/libdvm.so
  #05  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #06  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

"JDWP" daemon prio=5 tid=4 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x4213d2f8 self=0x59298370
  | sysTid=6018 nice=0 sched=0/0 cgrp=apps handle=1495892264
  | state=S schedstat=( 526723 2311140 11 ) utm=0 stm=0 core=2
  #00  pc 0001c0c4  /system/lib/libc.so (recvmsg+8)
  #01  pc 00060a5b  /system/lib/libdvm.so
  #02  pc 00060c8f  /system/lib/libdvm.so
  #03  pc 0006395f  /system/lib/libdvm.so
  #04  pc 0005440d  /system/lib/libdvm.so
  #05  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #06  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
  | group="system" sCount=0 dsCount=0 obj=0x4213d200 self=0x59297ad0
  | sysTid=6017 nice=0 sched=0/0 cgrp=apps handle=1495890056
  | state=R schedstat=( 17944062 3806465 24 ) utm=1 stm=0 core=2
  at dalvik.system.NativeStart.run(Native Method)

"GC" daemon prio=5 tid=2 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x4213d120 self=0x59297230
  | sysTid=6016 nice=0 sched=0/0 cgrp=apps handle=1495887848
  | state=S schedstat=( 46052188 14643875 115 ) utm=3 stm=0 core=0
  #00  pc 0001c5f0  /system/lib/libc.so (__futex_syscall3+8)
  #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
  #02  pc 0000e708  /system/lib/libc.so (__pthread_cond_timedwait+64)
  #03  pc 00071d5f  /system/lib/libdvm.so
  #04  pc 0005440d  /system/lib/libdvm.so
  #05  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #06  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

NATIVE THREADS:
"ybroad.launcher" sysTid=6044 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 28535 0 1 ) utm=0 stm=0 core=2

"ybroad.launcher" sysTid=6045 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 5934826 18041494 192 ) utm=0 stm=0 core=0

"ybroad.launcher" sysTid=6047 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 41991903 31647623 449 ) utm=0 stm=3 core=0

"ybroad.launcher" sysTid=6048 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 8821631 43405553 239 ) utm=0 stm=0 core=1

----- end 6012 -----


----- pid 1375 at 2014-08-16 12:44:43 -----
Cmd line: system_server

JNI: CheckJNI is off; workarounds are off; pins=3; globals=593 (plus 30 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=0x41e9a578 self=0x41d10778
  | sysTid=1375 nice=0 sched=0/0 cgrp=apps handle=1074671612
  | state=S schedstat=( 23099158711 5734754939 194687 ) utm=1476 stm=833 core=0
  #00  pc 0001b320  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002b9ab  /system/lib/libc.so (ioctl+14)
  #02  pc 0001b539  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
  #03  pc 0001bcd7  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 000013c3  /system/lib/libsystem_server.so (system_init+378)
  #05  pc 0001dc4c  /system/lib/libdvm.so (dvmPlatformInvoke+112)
  #06  pc 0004df2f  /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+398)
  #07  pc 00027060  /system/lib/libdvm.so
  #08  pc 0002b64c  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
  #09  pc 0006023f  /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+350)
  #10  pc 00067e3f  /system/lib/libdvm.so
  #11  pc 00027060  /system/lib/libdvm.so
  #12  pc 0002b64c  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
  #13  pc 0005ff81  /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292)
  #14  pc 00049bc7  /system/lib/libdvm.so
  #15  pc 0004bd87  /system/lib/libandroid_runtime.so
  #16  pc 0004ca17  /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+378)
  #17  pc 0000105b  /system/bin/app_process
  #18  pc 0000db4f  /system/lib/libc.so (__libc_init+50)
  #19  pc 00000d7c  /system/bin/app_process
  at com.android.server.SystemServer.init1(Native Method)
  at com.android.server.SystemServer.main(SystemServer.java:1183)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:525)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:773)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:589)
  at dalvik.system.NativeStart.main(Native Method)

"AsyncTask #2" prio=5 tid=89 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x423a6b98 self=0x59771d08
  | sysTid=2391 nice=0 sched=0/0 cgrp=apps handle=1500973936
  | state=S schedstat=( 3672799 2067535 16 ) utm=0 stm=0 core=3
  at java.lang.Object.wait(Native Method)
  - waiting on <0x421a1be8> (a java.lang.VMThread) held by tid=89 (AsyncTask #2)
  at java.lang.Thread.parkFor(Thread.java:1205)
  at sun.misc.Unsafe.park(Unsafe.java:325)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:841)

"WifiMonitor" prio=5 tid=88 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x42334b20 self=0x59767270
  | sysTid=2262 nice=0 sched=0/0 cgrp=apps handle=1496667712
  | state=S schedstat=( 2650153 18957633 18 ) utm=0 stm=0 core=2
  #00  pc 0001c4b0  /system/lib/libc.so (poll+12)
  #01  pc 00005ccb  /system/lib/libhardware_legacy.so (wifi_ctrl_recv+66)
  #02  pc 00005d85  /system/lib/libhardware_legacy.so (wifi_wait_on_socket+44)
  #03  pc 0006bd8f  /system/lib/libandroid_runtime.so
  #04  pc 0001dc4c  /system/lib/libdvm.so (dvmPlatformInvoke+112)
  #05  pc 0004df2f  /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+398)
  #06  pc 00027060  /system/lib/libdvm.so
  #07  pc 0002b64c  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
  #08  pc 0005ff81  /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292)
  #09  pc 0005ffab  /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20)
  #10  pc 00054d2b  /system/lib/libdvm.so
  #11  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #12  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at android.net.wifi.WifiNative.waitForEvent(Native Method)
  at android.net.wifi.WifiNative.waitForEvent(WifiNative.java:101)
  at android.net.wifi.WifiMonitor$MonitorThread.run(WifiMonitor.java:428)

"WifiMonitor" prio=5 tid=79 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x423b1ab8 self=0x59766e20
  | sysTid=2243 nice=0 sched=0/0 cgrp=apps handle=1500579736
  | state=S schedstat=( 18832173 27053387 77 ) utm=0 stm=1 core=1
  #00  pc 0001c4b0  /system/lib/libc.so (poll+12)
  #01  pc 00005ccb  /system/lib/libhardware_legacy.so (wifi_ctrl_recv+66)
  #02  pc 00005d85  /system/lib/libhardware_legacy.so (wifi_wait_on_socket+44)
  #03  pc 0006bd8f  /system/lib/libandroid_runtime.so
  #04  pc 0001dc4c  /system/lib/libdvm.so (dvmPlatformInvoke+112)
  #05  pc 0004df2f  /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+398)
  #06  pc 00027060  /system/lib/libdvm.so
  #07  pc 0002b64c  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
  #08  pc 0005ff81  /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292)
  #09  pc 0005ffab  /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20)
  #10  pc 00054d2b  /system/lib/libdvm.so
  #11  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #12  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at android.net.wifi.WifiNative.waitForEvent(Native Method)
  at android.net.wifi.WifiNative.waitForEvent(WifiNative.java:101)
  at android.net.wifi.WifiMonitor$MonitorThread.run(WifiMonitor.java:428)

"Binder_C" prio=5 tid=87 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x423125c0 self=0x5977ef58
  | sysTid=1901 nice=0 sched=0/0 cgrp=apps handle=1496648368
  | state=S schedstat=( 26136515152 5573609667 186413 ) utm=1517 stm=1096 core=3
  #00  pc 0001c5f4  /system/lib/libc.so (__futex_syscall3+12)
  #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
  #02  pc 00020771  /system/lib/libinput.so
  #03  pc 00022019  /system/lib/libinput.so (android::InputDispatcher::injectInputEvent(android::InputEvent const*, int, int, int, int, unsigned int)+800)
  #04  pc 0000a9ff  /system/lib/libandroid_servers.so
  #05  pc 0001dc4c  /system/lib/libdvm.so (dvmPlatformInvoke+112)
  #06  pc 0004df2f  /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+398)
  #07  pc 00027060  /system/lib/libdvm.so
  #08  pc 0002b64c  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
  #09  pc 0005ff81  /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292)
  #10  pc 0004cc91  /system/lib/libdvm.so
  #11  pc 0006b213  /system/lib/libandroid_runtime.so
  #12  pc 0006f82f  /system/lib/libandroid_runtime.so
  #13  pc 00017f1d  /system/lib/libbinder.so (android::BBinder::transact(unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+60)
  #14  pc 0001b8e5  /system/lib/libbinder.so (android::IPCThreadState::executeCommand(int)+508)
  #15  pc 0001bcf3  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+182)
  #16  pc 0001fae9  /system/lib/libbinder.so
  #17  pc 00011a8d  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
  #18  pc 0004bd21  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
  #19  pc 00011581  /system/lib/libutils.so
  #20  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #21  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at com.android.server.input.InputManagerService.nativeInjectInputEvent(Native Method)
  at com.android.server.input.InputManagerService.injectInputEvent(InputManagerService.java:534)
  at android.hardware.input.IInputManager$Stub.onTransact(IInputManager.java:170)
  at android.os.Binder.execTransact(Binder.java:388)
  at dalvik.system.NativeStart.run(Native Method)

"Binder_B" prio=5 tid=86 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4236ee80 self=0x5978c908
  | sysTid=1900 nice=0 sched=0/0 cgrp=apps handle=1501033856
  | state=S schedstat=( 18675932575 2816663578 195259 ) utm=1086 stm=781 core=0
  #00  pc 0001b320  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002b9ab  /system/lib/libc.so (ioctl+14)
  #02  pc 0001b539  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
  #03  pc 0001bcd7  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001fae9  /system/lib/libbinder.so
  #05  pc 00011a8d  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
  #06  pc 0004bd21  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
  #07  pc 00011581  /system/lib/libutils.so
  #08  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

"Binder_A" prio=5 tid=82 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x422c66e0 self=0x59288458
  | sysTid=1899 nice=0 sched=0/0 cgrp=apps handle=1473754056
  | state=S schedstat=( 28407006674 1139065291 197317 ) utm=1753 stm=1086 core=3
  #00  pc 0001b320  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002b9ab  /system/lib/libc.so (ioctl+14)
  #02  pc 0001b539  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
  #03  pc 0001bcd7  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001fae9  /system/lib/libbinder.so
  #05  pc 00011a8d  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
  #06  pc 0004bd21  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
  #07  pc 00011581  /system/lib/libutils.so
  #08  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

"pool-1-thread-1" prio=5 tid=85 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x42360de0 self=0x5977c7c8
  | sysTid=1869 nice=0 sched=0/0 cgrp=apps handle=1501023256
  | state=S schedstat=( 36792546 37524468 105 ) utm=2 stm=1 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x422ad870> (a java.lang.VMThread) held by tid=85 (pool-1-thread-1)
  at java.lang.Thread.parkFor(Thread.java:1205)
  at sun.misc.Unsafe.park(Unsafe.java:325)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:841)

"SoundPoolThread" prio=5 tid=84 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4234dd18 self=0x59288008
  | sysTid=1787 nice=0 sched=0/0 cgrp=apps handle=1501052992
  | state=S schedstat=( 2719918 1463037 21 ) utm=0 stm=0 core=1
  #00  pc 0001c5f0  /system/lib/libc.so (__futex_syscall3+8)
  #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
  #02  pc 0000e708  /system/lib/libc.so (__pthread_cond_timedwait+64)
  #03  pc 000697e9  /system/lib/libmedia.so
  #04  pc 0006983b  /system/lib/libmedia.so (android::SoundPoolThread::read()+16)
  #05  pc 000699e7  /system/lib/libmedia.so (android::SoundPoolThread::run()+14)
  #06  pc 0004bd21  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
  #07  pc 00011581  /system/lib/libutils.so
  #08  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

"SoundPool" prio=5 tid=83 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x422b7470 self=0x5977fdc8
  | sysTid=1785 nice=0 sched=0/0 cgrp=apps handle=1501039224
  | state=S schedstat=( 43918396 52908113 631 ) utm=0 stm=4 core=1
  #00  pc 0001c5f0  /system/lib/libc.so (__futex_syscall3+8)
  #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
  #02  pc 0000e708  /system/lib/libc.so (__pthread_cond_timedwait+64)
  #03  pc 0006937f  /system/lib/libmedia.so (android::SoundPool::run()+20)
  #04  pc 0004bd21  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
  #05  pc 00011581  /system/lib/libutils.so
  #06  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
  #07  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
  at dalvik.system.NativeStart.run(Native Method)

參考frameworks\base\services\java\com\android\server\am\ActivityManagerService.java 中的appNotResponding函式的處理流程可以看出trace.txt 檔案的生成過程，在trace.txt 檔案中一般第一程序為發生ANR的程序。分析上面的trace.txt中的第一個程序 com.hybroad.launcher是產生ANR的程序，與Log日誌也匹配，通過檢視執行緒狀態，可以看出ViewRoot重新整理UI是阻塞了。trace日誌中還能看出com.hybroad.launcher中多個非同步任務都是在在WAIT狀態，如PriorityExecutor #5" prio=5 tid=15 WAIT，這些非同步任務是從後臺下載圖片顯示。這裡巧合的是Monkey程式觸發的操作邏輯導致UI重新整理阻塞。

三、如何避免ANR

要想不出現ANR是很困難的，但也是有辦法能避免的。在主執行緒中所做的任何耗時的操作都有可能造成ANR，因為這些耗時的操作會使得主執行緒沒有機會處理使用者輸入事件或者廣播事件。因此在主執行緒中執行的任何函式所做的工作都應該儘可能的少，特別是對於Activity的生命週期函式來說。網路和資料庫操作，讀寫裝置，以及諸如點陣圖變換的一些耗時的操作，都應該放在子執行緒中完成。主執行緒不需要等待子執行緒的執行，主執行緒應該建立一個與其繫結的Handler物件，子執行緒執行完畢後通過 Handler通知主執行緒。

Android 系統穩定性之ANR

Android 系統穩定性之ANR

android系統穩定性-ANR(二)

Android App優化之ANR詳解

Android系統APP之SettingsProvider

Android系統篇之----免root實現Hook系統服務攔截方法

Android系統分析之ThreadLocal

Android系統開發之燒錄開發板

android系統裁剪之APP精簡

Android系統篇之----編寫系統服務並且將其編譯到系統原始碼中

Android系統分析之Activity的啟動流程

定製Android系統開發之四——系統服務實現的分析

Android系統穩定性----Crash

Android系統服務之看門狗(WatchDog)

Android系統程序之Activity管理——ActivityManagerService（AMS）

Android系統工具之Traceview的使用

Android 系統穩定性

讀Android系統篇之-免root實現Hook系統服務攔截方法

Android系統篇之----解讀AMS遠端服務呼叫機制以及Activity的啟動流程

Android 系統編譯之核心編譯

android系統裁減之服務裁減

Android 系統穩定性之ANR

相關推薦