Android ANR無響應分析解決方案
更新時間：2022年12月15日 11:43:47 作者：itbird01
這篇文章主要為大家介紹了Android ANR無響應分析解決方案，有需要的朋友可以借鑒參考下，希望能夠有所幫助，祝大家多多進步，早日升職加薪
1.什么是 ANR
ANR:Application Not Responding ，即應用無響應
2.ANR 的類型以及對比每種類型的規(guī)避解決方法
ANR 一般有三種類型：
1）KeyDispatchTimeout(5 seconds) 按鍵或觸摸事件在特定時間內(nèi)無響應
2）BroadcastTimeout(10 seconds) BroadcastReceiver 在特定時間內(nèi)無法處理完成
3）ServiceTimeout(20 seconds or 200 seconds) 前臺服務：超時時間是 20s； 后臺服務，則超時時間是200s； Service 在特定的時間內(nèi)無法處理完成
2.1 KeyDispatchTimeout
Akey or touch event was not dispatched within the specified time （按鍵或觸摸事件在特定時間內(nèi)無響應）
具體的超時時間的定義在 framework 下的
ActivityManagerService.java //How long we wait until we timeout on key dispatching. staticfinal int KEY_DISPATCHING_TIMEOUT = 5*1000
為什么會超時呢？ 超時時間的計數(shù)一般是從按鍵分發(fā)給 app 開始。超時的原因一般有兩種 ： 1）當前的事件沒有機會得到處理（即 UI 線程正在處理前一個事件，沒有及時的完成或者 looper 被某種原因阻塞住了） 2）當前的事件正在處理，但沒有及時完成
如何避免 KeyDispatchTimeout？ 1）UI 線程盡量只做跟 UI 相關(guān)的工作 2）耗時的工作（比如數(shù)據(jù)庫操作， I/O ，連接網(wǎng)絡或者別的有可能阻礙 UI 線程的操作）把它放入單獨的線程處理 3）盡量用 Handler 來處理 UIthread 和別的 thread 之間的交互
至于Service和BroadcastReceiver ，和上面的分析同理，這里就不多說了。
3.如何分析ANR日志？
先看個 LOG：
04-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--- 發(fā)生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 發(fā)生前的使用情況
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
從ANR日志中，我們看到了ANR in com.android.email關(guān)鍵字，然后接下來，我們看到Reason:keyDispatchingTimedOut，是在事件響應里面超時了，但是具體在哪里，這里看不出來，但是這里可以看到一個信息，即：ANR的原因是CPU占用率高，任務得不到時間片去執(zhí)行，還是因為IO密集，導致ANR，這個很重要，可以給我們之后分析具體的trace日志提供方向。
除了看 LOG ，解決 ANR 還得需要 trace.txt 文件，如何獲取呢？可以用如下命令獲取
$chmod 777 /data/anr $rm /data/anr/traces.txt $ps $kill -3 PID adb pull data/anr/traces.txt ./mytraces.txt
從 trace.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=1 NATIVE | 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)
我們從這里看到，是主線程卡在了nativePollOnce這里，從之前小編分析過handler、MQ源碼可知，這個是消息隊列為空，在等待下一條消息入隊，進行主線程喚醒，也就是說主線程死在，一直等待，等待超時了。
小結(jié)： 如何調(diào)查并解決 ANR？
1）首先分析 log，看一下大概原因，如果能直接定位最好，但是一般這里直接定位不到的
2）從 trace.txt 文件查看調(diào)用 stack.
3）對照每個線程日志，看自己代碼
4）過程中，緊緊穿插一條主線，仔細查看 ANR 的成因（ iowait?block?memoryleak? ）
4.案例分析
4.1 IO wait舉例
Process:com.android.email Activity:com.android.email/.activity.MessageView Subject: keyDispatchingTimedOut CPU usage from 2550ms to -2814ms ago: 5%187 /system_server: 3.5% user + 1.4% kernel / faults: 86 minor 20major 4.4% 1134/com.android.email: 0.7% user + 3.7% kernel /faults: 38 minor 19 major 4% 372/com.android.eventstream: 0.7%user + 3.3% kernel / faults: 6 minor 1.1% 272/com.android.phone:0.9% user + 0.1% kernel / faults: 33 minor 0.9%252/com.android.systemui: 0.9% user + 0% kernel 0%409/com.android.eventstream.telephonyplugin: 0% user + 0% kernel /faults: 2 minor 0.1% 632/com.android.devicemonitor: 0.1% user + 0%kernel 100%TOTAL: 6.9% user + 8.2% kernel + 84%iowait -----pid 1134 at 2010-12-17 17:46:51 ----- Cmd line:com.android.email DALVIK THREADS: (mutexes: tll=0 tsl=0tscl=0 ghl=0 hwl=0 hwll=0) "main" prio=5 tid=1 WAIT |group="main" sCount=1 dsCount=0 obj=0x2aaca180self=0xcf20 | sysTid=1134 nice=0 sched=0/0 cgrp=[fopen-error:2]handle=1876218976 at java.lang.Object.wait(Native Method) -waiting on <0x2aaca218> (a java.lang.VMThread) atjava.lang.Thread.parkFor(Thread.java:1424) atjava.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) atsun.misc.Unsafe.park(Unsafe.java:337) atjava.util.concurrent.locks.LockSupport.park(LockSupport.java:157) atjava.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:808) atjava.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:841) atjava.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1171) atjava.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200) atjava.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261) atandroid.database.sqlite.SQLiteDatabase.lock(SQLiteDatabase.java:378) atandroid.database.sqlite.SQLiteCursor.<init>(SQLiteCursor.java:222) atandroid.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:53) atandroid.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1356) atandroid.database.sqlite.SQLiteDatabase.queryWithFactory(SQLiteDatabase.java:1235) atandroid.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1189) atandroid.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1271) atcom.android.email.provider.EmailProvider.query(EmailProvider.java:1098) atandroid.content.ContentProvider$Transport.query(ContentProvider.java:187) atandroid.content. ContentResolver.query (ContentResolver.java:268) atcom.android.email.provider.EmailContent$Message.restoreMessageWithId(EmailContent.java:648) atcom.android.email.Controller.setMessageRead(Controller.java:658) atcom.android.email.activity.MessageView.onMarkAsRead(MessageView.java:700) atcom.android.email.activity.MessageView.access$2500(MessageView.java:98) atcom.android.email.activity.MessageView$LoadBodyTask .onPostExecute(MessageView.java:1290) atcom.android.email.activity.MessageView$LoadBodyTask.onPostExecute(MessageView.java:1255) atandroid.os.AsyncTask.finish(AsyncTask.java:417) atandroid.os.AsyncTask.access$300(AsyncTask.java:127) at android.os.AsyncTask $InternalHandler.handleMessage (AsyncTask.java:429) atandroid.os.Handler.dispatchMessage(Handler.java:99) atandroid.os.Looper.loop(Looper.java:123) atandroid.app.ActivityThread.main(ActivityThread.java:3652) atjava.lang.reflect.Method.invokeNative(Native Method) atjava.lang.reflect.Method.invoke(Method.java:507) atcom.android.internal.os.ZygoteIn
我們從日志上，看到關(guān)鍵字84%iowait，而且對于cpu來說，這段日志占用很少，說明大概原因就是IO密集型導致，從下面日志中看到，有View、有ContentProvider、有Sqlite、有鎖，我們先大膽猜測一下，是否是在主線程里面，進行了數(shù)據(jù)庫操作導致的？
具體看日志，我們代碼中應該有在view內(nèi)部調(diào)用ContentResolver的地方，快搜一下，我們代碼中，是否有這樣的調(diào)用，果然一搜，的確有：
final Message message = Message . restoreMessageWithId (mProviderContext , messageId );
if ( message == null ) {
return ;
}
Account account = Account . restoreAccountWithId ( mProviderContext ,message . mAccountKey );
if ( account == null ) {
return ; //isMessagingController returns false for null, but let's make itclear.
}
if ( isMessagingController ( account )) {
new Thread () {
@Override
public void run () {
mLegacyController . processPendingActions ( message .mAccountKey );
}
}. start ();
}
發(fā)現(xiàn)問題了沒有呢？這里在主線程中調(diào)用了Account . restoreAccountWithId ( mProviderContext ,message . mAccountKey );去查詢數(shù)據(jù)，如果正常系統(tǒng)資源不緊張的時候，這樣調(diào)用的確不會出現(xiàn)太大問題，但是假設這個數(shù)據(jù)很大、或者系統(tǒng)當前IO繁忙，這兒代碼不就執(zhí)行很慢，導致主線程事件處理超時了嗎？ 所以把代碼，簡單改為如下，運行沒有問題了。
new Thread() {
final Message message = Message . restoreMessageWithId (mProviderContext , messageId );
if ( message == null ) {
return ;
}
Account account = Account . restoreAccountWithId ( mProviderContext ,message . mAccountKey );
if ( account == null ) {
return ; //isMessagingController returns false for null, but let's make itclear.
}
if(isMessagingController(account)) {
mLegacyController.processPendingActions(message.mAccountKey);
}
}.start();
4.2Memoryleak/Thread leak
11-1621:41:42.560 I/ActivityManager( 1190): ANR in process:android.process.acore (last in android.process.acore) 11-1621:41:42.560 I/ActivityManager( 1190): Annotation:keyDispatchingTimedOut 11-16 21:41:42.560 I/ActivityManager(1190): CPU usage: 11-16 21:41:42.560 I/ActivityManager( 1190):Load: 11.5 / 11.1 / 11.09 11-16 21:41:42.560 I/ActivityManager(1190): CPU usage from 9046ms to 4018ms ago: 11-16 21:41:42.560 I/ActivityManager( 1190): d.process.acore:98% = 97% user + 0% kernel / faults: 1134 minor 11-16 21:41:42.560 I/ActivityManager( 1190): system_server: 0% = 0% user + 0% kernel /faults: 1 minor 11-16 21:41:42.560 I/ActivityManager( 1190): adbd:0% = 0% user + 0% kernel 11-16 21:41:42.560 I/ActivityManager(1190): logcat: 0% = 0% user + 0% kernel 11-16 21:41:42.560 I/ActivityManager( 1190): TOTAL:100% = 98% user + 1% kernel Cmdline: android.process.acore DALVIK THREADS: "main"prio=5 tid=3 VMWAIT |group="main" sCount=1 dsCount=0 s=N obj=0x40026240self=0xbda8 | sysTid=1815 nice=0 sched=0/0 cgrp=unknownhandle=-1344001376 atdalvik.system.VMRuntime.trackExternalAllocation (NativeMethod ) atandroid.graphics.Bitmap.nativeCreate(Native Method) atandroid.graphics.Bitmap.createBitmap (Bitmap.java:468) atandroid.view.View.buildDrawingCache(View.java:6324) atandroid.view.View.getDrawingCache(View.java:6178) atandroid.view.ViewGroup.drawChild(ViewGroup.java:1541) atcom.android.internal.policy.impl.PhoneWindow$DecorView.draw(PhoneWindow.java:1830) atandroid.view.ViewRoot.draw(ViewRoot.java:1349) atandroid.view.ViewRoot.performTraversals(ViewRoot.java:1114) atandroid.view.ViewRoot.handleMessage(ViewRoot.java:1633) atandroid.os.Handler.dispatchMessage(Handler.java:99) atandroid.os.Looper.loop(Looper.java:123) atandroid.app.ActivityThread.main(ActivityThread.java:4370) atjava.lang.reflect.Method.invokeNative(Native Method) atjava.lang.reflect.Method.invoke(Method.java:521) atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868) atcom.android.internal.os.ZygoteInit.main(ZygoteInit.java:626) atdalvik.system.NativeStart.main(Native Method) "Thread-408"prio=5 tid=329 WAIT |group="main" sCount=1 dsCount=0 s=N obj=0x46910d40self=0xcd0548 | sysTid=10602 nice=0 sched=0/0 cgrp=unknownhandle=15470792 at java.lang.Object.wait(Native Method) -waiting on <0x468cd420> (a java.lang.Object) atjava.lang.Object.wait(Object.java:288) atcom.android.dialer.CallLogContentHelper$UiUpdaterExecutor$1.run(CallLogContentHelper.java:289) atjava.lang.Thread.run(Thread.java:1096)
我們看到日志中，ANR發(fā)生在VMRuntime中，有關(guān)鍵字Bitmap、createBitmap 、nativeCreate、ViewRoot、ActivityThread#main，我們大膽猜測一下，是否是在主線程視圖繪制函數(shù)中，進行了大圖片的加載、申請了bitmap沒有釋放導致，仔細看日志，發(fā)現(xiàn)at dalvik.system. VMRuntime.trackExternalAllocation (NativeMethod ) ，bitmap在申請內(nèi)存的時候，不夠了，這時block了。
解決很簡單，這時根據(jù)后面的線程、進程、堆棧詳細信息，去反向猜測&查找相關(guān)代碼，是否存在可能內(nèi)存泄露的地方。
以上就是Android ANR無響應分析解決方案的詳細內(nèi)容，更多關(guān)于Android ANR無響應的資料請關(guān)注腳本之家其它相關(guān)文章！
相關(guān)文章
本文主要介紹Android應用程序簽名相關(guān)的理論知識，包括：什么是簽名、為什么要給應用程序簽名、如何給應用程序簽名等,感興趣的朋友可以參考下哈2013-04-04
Android實現(xiàn)文字動態(tài)高亮讀取進度效果
這篇文章主要為大家詳細介紹了Android實現(xiàn)文字動態(tài)高亮讀取進度效果，文中示例代碼介紹的非常詳細，具有一定的參考價值，感興趣的小伙伴們可以參考一下2021-05-05
Kotlin自定義View系列教程之標尺控件（選擇身高、體重等）的實現(xiàn)
這篇文章主要給大家介紹了關(guān)于Kotlin自定義View系列教程之標尺控件（選擇身高、體重等）實現(xiàn)的相關(guān)資料，文中通過示例代碼介紹的非常詳細，需要的朋友可以參考借鑒，下面隨著小編來一起學習學習吧2018-07-07
這篇文章主要介紹了Android源碼中常用的接口傳參實例詳解的相關(guān)資料,需要的朋友可以參考下2017-04-04
Android自定義控件之繼承ViewGroup創(chuàng)建新容器
這篇文章主要介紹了Android自定義控件之繼承ViewGroup創(chuàng)建新容器,具有一定的參考價值，感興趣的小伙伴們可以參考一下2016-12-12
Android App開發(fā)中使用RecyclerView替代ListView的實踐
RecyclerView是Android L即5.0版本以來新加入的一個組件,主要用來實現(xiàn)item的瀑布式排列,因而被人們廣泛認為用來替代ListView,這里我們就來看一下Android App開發(fā)中使用RecyclerView替代ListView的實踐:2016-06-06
這篇文章主要介紹了Android開發(fā)之電話撥號器,結(jié)合實例形式詳細分析了Android電話撥號器的實現(xiàn)步驟與具體代碼,并附帶了一個Android開放電話撥號器的學習筆記,需要的朋友可以參考下2015-12-12
Qt6.5.3?Android環(huán)境配置的實現(xiàn)
本文主要介紹了Qt6.5.3?Android環(huán)境配置的實現(xiàn),文中通過圖文介紹的非常詳細,對大家的學習或者工作具有一定的參考學習價值,需要的朋友們下面隨著小編來一起學習學習吧2024-01-01
這篇文章主要介紹了Action獲取請求參數(shù)的三種方式的,非常不錯，具有參考借鑒價值,需要的朋友可以參考下2016-06-06
這篇文章主要為大家詳細介紹了Android仿通話來電界面效果，文中示例代碼介紹的非常詳細，具有一定的參考價值，感興趣的小伙伴們可以參考一下2021-09-09